[
https://issues.apache.org/jira/browse/CASSANDRA-9310?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Kishan Karunaratne updated CASSANDRA-9310:
------------------------------------------
Description:
When an index is dropped, its existence is still persisted across the keyspace
metadata. This happens because the response to drop the index from the metadata
is never received, as a keyspace change response is (incorrectly) received by
the driver instead of a table change response.
Test:
{noformat}
self.session.execute("CREATE TABLE %s (k int PRIMARY KEY, a int)" %
self.table_name)
ks_meta = self.cluster.metadata.keyspaces[self.keyspace_name]
table_meta = ks_meta.tables[self.table_name]
self.assertNotIn('a_idx', ks_meta.indexes)
self.assertNotIn('b_idx', ks_meta.indexes)
self.assertNotIn('a_idx', table_meta.indexes)
self.assertNotIn('b_idx', table_meta.indexes)
self.session.execute("CREATE INDEX a_idx ON %s (a)" % self.table_name)
self.session.execute("ALTER TABLE %s ADD b int" % self.table_name)
self.session.execute("CREATE INDEX b_idx ON %s (b)" % self.table_name)
ks_meta = self.cluster.metadata.keyspaces[self.keyspace_name]
table_meta = ks_meta.tables[self.table_name]
self.assertIsInstance(ks_meta.indexes['a_idx'], IndexMetadata)
self.assertIsInstance(ks_meta.indexes['b_idx'], IndexMetadata)
self.assertIsInstance(table_meta.indexes['a_idx'], IndexMetadata)
self.assertIsInstance(table_meta.indexes['b_idx'], IndexMetadata)
# both indexes updated when index dropped
self.session.execute("DROP INDEX a_idx")
ks_meta = self.cluster.metadata.keyspaces[self.keyspace_name]
table_meta = ks_meta.tables[self.table_name]
self.assertNotIn('a_idx', ks_meta.indexes)
{noformat}
Output:
{noformat}
AssertionError: 'a_idx' unexpectedly found in {u'b_idx':
<cassandra.metadata.IndexMetadata object at 0x7f2dd87d4590>, u'a_idx':
<cassandra.metadata.IndexMetadata object at 0x7f2dd87d4a10>}
{noformat}
Debug log:
{noformat}
tests.integration: INFO: Using Cassandra version: 1.2.19
tests.integration: DEBUG: Creating new ccm test_cluster cluster with
{'version': '1.2.19'}
tests.integration: DEBUG: Starting ccm test_cluster cluster
cassandra.cluster: DEBUG: Connecting to cluster, contact points: ['127.0.0.1'];
protocol version: 1
cassandra.pool: DEBUG: Host 127.0.0.1 is now marked up
cassandra.cluster: DEBUG: [control connection] Opening new connection to
127.0.0.1
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309742864976) to 127.0.0.1
cassandra.io.libevreactor: DEBUG: Starting libev event loop
cassandra.connection: DEBUG: Received options response on new connection
(140309742864976) from 127.0.0.1
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309742864976) 127.0.0.1:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309742864976) 127.0.0.1:9042>
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309742864976) from 127.0.0.1
cassandra.cluster: DEBUG: [control connection] Established new connection
<LibevConnection(140309742864976) 127.0.0.1:9042>, registering watchers and
refreshing schema and topology
cassandra.cluster: DEBUG: [control connection] Refreshing node list and token
map using preloaded results
cassandra.cluster: DEBUG: [control connection] Found new host to connect to:
127.0.0.3
cassandra.cluster: INFO: New Cassandra host <Host: 127.0.0.3 dc1> discovered
cassandra.cluster: DEBUG: Handling new host <Host: 127.0.0.3 dc1> and notifying
listeners
cassandra.cluster: DEBUG: Done preparing queries for new host <Host: 127.0.0.3
dc1>
cassandra.pool: DEBUG: Host 127.0.0.3 is now marked up
cassandra.cluster: DEBUG: [control connection] Found new host to connect to:
127.0.0.2
cassandra.cluster: INFO: New Cassandra host <Host: 127.0.0.2 dc1> discovered
cassandra.cluster: DEBUG: Handling new host <Host: 127.0.0.2 dc1> and notifying
listeners
cassandra.cluster: DEBUG: Done preparing queries for new host <Host: 127.0.0.2
dc1>
cassandra.pool: DEBUG: Host 127.0.0.2 is now marked up
cassandra.cluster: DEBUG: [control connection] Finished fetching ring info
cassandra.cluster: DEBUG: [control connection] Rebuilding token map due to
topology changes
cassandra.cluster: DEBUG: [control connection] Attempting to use preloaded
results for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] triggers table not found
cassandra.cluster: DEBUG: [control connection] user types table not found
cassandra.cluster: DEBUG: [control connection] Fetched schema, rebuilding
metadata
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.HintsColumnFamily
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.IndexInfo
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.LocationInfo
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.Migrations
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.NodeIdInfo
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.Schema
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.hints
cassandra.cluster: DEBUG: Control connection created
cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.3
cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.2
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309742557904) to 127.0.0.2
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309743075024) to 127.0.0.3
cassandra.connection: DEBUG: Received options response on new connection
(140309743075024) from 127.0.0.3
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309743075024) 127.0.0.3:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309743075024) 127.0.0.3:9042>
cassandra.connection: DEBUG: Received options response on new connection
(140309742557904) from 127.0.0.2
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309742557904) 127.0.0.2:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309742557904) 127.0.0.2:9042>
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309743075024) from 127.0.0.3
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309742557904) from 127.0.0.2
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309742557200) to 127.0.0.2
cassandra.connection: DEBUG: Received options response on new connection
(140309742557200) from 127.0.0.2
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309742557200) 127.0.0.2:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309742557200) 127.0.0.2:9042>
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309742558608) to 127.0.0.3
cassandra.connection: DEBUG: Received options response on new connection
(140309742558608) from 127.0.0.3
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309742558608) 127.0.0.3:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309742558608) 127.0.0.3:9042>
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309742558608) from 127.0.0.3
cassandra.pool: DEBUG: Finished initializing new connection pool for host
127.0.0.3
cassandra.cluster: DEBUG: Added pool for host 127.0.0.3 to session
cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.1
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309742559056) to 127.0.0.1
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309742557200) from 127.0.0.2
cassandra.connection: DEBUG: Received options response on new connection
(140309742559056) from 127.0.0.1
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309742559056) 127.0.0.1:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309742559056) 127.0.0.1:9042>
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309742559056) from 127.0.0.1
cassandra.pool: DEBUG: Finished initializing new connection pool for host
127.0.0.2
cassandra.cluster: DEBUG: Added pool for host 127.0.0.2 to session
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309742557840) to 127.0.0.1
cassandra.connection: DEBUG: Received options response on new connection
(140309742557840) from 127.0.0.1
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309742557840) 127.0.0.1:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309742557840) 127.0.0.1:9042>
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309742557840) from 127.0.0.1
cassandra.pool: DEBUG: Finished initializing new connection pool for host
127.0.0.1
cassandra.cluster: DEBUG: Added pool for host 127.0.0.1 to session
cassandra.connection: DEBUG: Message pushed from server:
<EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
event_args={'keyspace': u'test3rf', 'change_type': u'CREATED', 'table': u''},
trace_id=None)>
cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
Keyspace: test3rf; Table: , Type: None
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
test3rf, rebuilding metadata
cassandra.connection: DEBUG: Message pushed from server:
<EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
event_args={'keyspace': u'test2rf', 'change_type': u'CREATED', 'table': u''},
trace_id=None)>
cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
Keyspace: test2rf; Table: , Type: None
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
test2rf, rebuilding metadata
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
test3rf, rebuilding metadata
cassandra.connection: DEBUG: Message pushed from server:
<EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
event_args={'keyspace': u'test1rf', 'change_type': u'CREATED', 'table': u''},
trace_id=None)>
cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
Keyspace: test1rf; Table: , Type: None
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
test1rf, rebuilding metadata
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
test2rf, rebuilding metadata
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
test1rf, rebuilding metadata
cassandra.connection: DEBUG: Message pushed from server:
<EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
event_args={'keyspace': u'test3rf', 'change_type': u'CREATED', 'table':
u'test'}, trace_id=None)>
cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
Keyspace: test3rf; Table: test, Type: None
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched table info for
test3rf.test, rebuilding metadata
cassandra.cluster: DEBUG: Shutting down Cluster Scheduler
cassandra.cluster: DEBUG: Shutting down control connection
cassandra.io.libevreactor: DEBUG: Closing connection (140309742864976) to
127.0.0.1
cassandra.cluster: DEBUG: Not executing scheduled task due to Scheduler shutdown
cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.1
cassandra.io.libevreactor: DEBUG: Closing connection (140309743075024) to
127.0.0.3
cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.3
cassandra.io.libevreactor: DEBUG: Closing connection (140309742558608) to
127.0.0.3
cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.3
cassandra.io.libevreactor: DEBUG: Closing connection (140309742557904) to
127.0.0.2
cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.2
cassandra.io.libevreactor: DEBUG: Closing connection (140309742557200) to
127.0.0.2
cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.2
cassandra.io.libevreactor: DEBUG: Closing connection (140309742559056) to
127.0.0.1
cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.1
cassandra.io.libevreactor: DEBUG: Closing connection (140309742557840) to
127.0.0.1
cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.1
cassandra.io.libevreactor: DEBUG: All Connections currently closed, event loop
ended
cassandra.cluster: DEBUG: Connecting to cluster, contact points: ['127.0.0.1'];
protocol version: 1
cassandra.pool: DEBUG: Host 127.0.0.1 is now marked up
cassandra.cluster: DEBUG: [control connection] Opening new connection to
127.0.0.1
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309742559120) to 127.0.0.1
cassandra.io.libevreactor: DEBUG: Starting libev event loop
cassandra.connection: DEBUG: Received options response on new connection
(140309742559120) from 127.0.0.1
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309742559120) 127.0.0.1:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309742559120) 127.0.0.1:9042>
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309742559120) from 127.0.0.1
cassandra.cluster: DEBUG: [control connection] Established new connection
<LibevConnection(140309742559120) 127.0.0.1:9042>, registering watchers and
refreshing schema and topology
cassandra.cluster: DEBUG: [control connection] Refreshing node list and token
map using preloaded results
cassandra.cluster: DEBUG: [control connection] Found new host to connect to:
127.0.0.3
cassandra.cluster: INFO: New Cassandra host <Host: 127.0.0.3 dc1> discovered
cassandra.cluster: DEBUG: Handling new host <Host: 127.0.0.3 dc1> and notifying
listeners
cassandra.cluster: DEBUG: Done preparing queries for new host <Host: 127.0.0.3
dc1>
cassandra.pool: DEBUG: Host 127.0.0.3 is now marked up
cassandra.cluster: DEBUG: [control connection] Found new host to connect to:
127.0.0.2
cassandra.cluster: INFO: New Cassandra host <Host: 127.0.0.2 dc1> discovered
cassandra.cluster: DEBUG: Handling new host <Host: 127.0.0.2 dc1> and notifying
listeners
cassandra.cluster: DEBUG: Done preparing queries for new host <Host: 127.0.0.2
dc1>
cassandra.pool: DEBUG: Host 127.0.0.2 is now marked up
cassandra.cluster: DEBUG: [control connection] Finished fetching ring info
cassandra.cluster: DEBUG: [control connection] Rebuilding token map due to
topology changes
cassandra.cluster: DEBUG: [control connection] Attempting to use preloaded
results for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] triggers table not found
cassandra.cluster: DEBUG: [control connection] user types table not found
cassandra.cluster: DEBUG: [control connection] Fetched schema, rebuilding
metadata
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.HintsColumnFamily
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.IndexInfo
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.LocationInfo
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.Migrations
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.NodeIdInfo
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.Schema
cassandra.metadata: WARNING: Building table metadata with no column meta for
system.hints
cassandra.cluster: DEBUG: Control connection created
cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.3
cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.2
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309700367952) to 127.0.0.2
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309742595920) to 127.0.0.3
cassandra.connection: DEBUG: Received options response on new connection
(140309700367952) from 127.0.0.2
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309700367952) 127.0.0.2:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309700367952) 127.0.0.2:9042>
cassandra.connection: DEBUG: Received options response on new connection
(140309742595920) from 127.0.0.3
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309742595920) 127.0.0.3:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309742595920) 127.0.0.3:9042>
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309700367952) from 127.0.0.2
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309742595920) from 127.0.0.3
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309742595856) to 127.0.0.3
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309700368784) to 127.0.0.2
cassandra.connection: DEBUG: Received options response on new connection
(140309742595856) from 127.0.0.3
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309742595856) 127.0.0.3:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309742595856) 127.0.0.3:9042>
cassandra.connection: DEBUG: Received options response on new connection
(140309700368784) from 127.0.0.2
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309700368784) 127.0.0.2:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309700368784) 127.0.0.2:9042>
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309742595856) from 127.0.0.3
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309700368784) from 127.0.0.2
cassandra.pool: DEBUG: Finished initializing new connection pool for host
127.0.0.3
cassandra.cluster: DEBUG: Added pool for host 127.0.0.3 to session
cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.1
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309700369232) to 127.0.0.1
cassandra.pool: DEBUG: Finished initializing new connection pool for host
127.0.0.2
cassandra.cluster: DEBUG: Added pool for host 127.0.0.2 to session
cassandra.connection: DEBUG: Received options response on new connection
(140309700369232) from 127.0.0.1
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309700369232) 127.0.0.1:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309700369232) 127.0.0.1:9042>
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309700369232) from 127.0.0.1
cassandra.connection: DEBUG: Sending initial options message for new connection
(140309700367888) to 127.0.0.1
cassandra.connection: DEBUG: Received options response on new connection
(140309700367888) from 127.0.0.1
cassandra.connection: DEBUG: Sending StartupMessage on
<LibevConnection(140309700367888) 127.0.0.1:9042>
cassandra.connection: DEBUG: Sent StartupMessage on
<LibevConnection(140309700367888) 127.0.0.1:9042>
cassandra.connection: DEBUG: Got ReadyMessage on new connection
(140309700367888) from 127.0.0.1
cassandra.pool: DEBUG: Finished initializing new connection pool for host
127.0.0.1
cassandra.cluster: DEBUG: Added pool for host 127.0.0.1 to session
cassandra.connection: DEBUG: Message pushed from server:
<EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
event_args={'keyspace': u'index_map_tests', 'change_type': u'CREATED', 'table':
u''}, trace_id=None)>
cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
Keyspace: index_map_tests; Table: , Type: None
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
index_map_tests, rebuilding metadata
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
index_map_tests, rebuilding metadata
cassandra.connection: DEBUG: Message pushed from server:
<EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
event_args={'keyspace': u'index_map_tests', 'change_type': u'CREATED', 'table':
u'test_index_updates'}, trace_id=None)>
cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
Keyspace: index_map_tests; Table: test_index_updates, Type: None
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched table info for
index_map_tests.test_index_updates, rebuilding metadata
cassandra.connection: DEBUG: Message pushed from server:
<EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
event_args={'keyspace': u'index_map_tests', 'change_type': u'UPDATED', 'table':
u'test_index_updates'}, trace_id=None)>
cassandra.cluster: DEBUG: Ignoring schedule_unique for already-scheduled task:
(<bound method ControlConnection.refresh_schema of
<cassandra.cluster.ControlConnection object at 0x7f9c6864fc90>>,
(u'index_map_tests', u'test_index_updates', None))
cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
Keyspace: index_map_tests; Table: test_index_updates, Type: None
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched table info for
index_map_tests.test_index_updates, rebuilding metadata
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched table info for
index_map_tests.test_index_updates, rebuilding metadata
cassandra.connection: DEBUG: Message pushed from server:
<EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
event_args={'keyspace': u'index_map_tests', 'change_type': u'UPDATED', 'table':
u'test_index_updates'}, trace_id=None)>
cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
Keyspace: index_map_tests; Table: test_index_updates, Type: None
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched table info for
index_map_tests.test_index_updates, rebuilding metadata
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched table info for
index_map_tests.test_index_updates, rebuilding metadata
cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
Keyspace: index_map_tests; Table: test_index_updates, Type: None
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.connection: DEBUG: Message pushed from server:
<EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
event_args={'keyspace': u'index_map_tests', 'change_type': u'UPDATED', 'table':
u'test_index_updates'}, trace_id=None)>
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched table info for
index_map_tests.test_index_updates, rebuilding metadata
cassandra.cluster: DEBUG: [control connection] Fetched table info for
index_map_tests.test_index_updates, rebuilding metadata
cassandra.connection: DEBUG: Message pushed from server:
<EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
event_args={'keyspace': u'index_map_tests', 'change_type': u'UPDATED', 'table':
u'test_index_updates'}, trace_id=None)>
cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
Keyspace: index_map_tests; Table: , Type: None
cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying again
cassandra.cluster: DEBUG: [control connection] Schemas match
cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
index_map_tests, rebuilding metadata
{noformat}
was:
When an index is dropped, its existence is still persisted across the keyspace
metadata. This happens because the response to drop the index from the metadata
is never received, as a keyspace change response is (incorrectly) received by
the driver instead of a table change response.
{noformat}
self.session.execute("CREATE TABLE %s (k int PRIMARY KEY, a int)" %
self.table_name)
ks_meta = self.cluster.metadata.keyspaces[self.keyspace_name]
table_meta = ks_meta.tables[self.table_name]
self.assertNotIn('a_idx', ks_meta.indexes)
self.assertNotIn('b_idx', ks_meta.indexes)
self.assertNotIn('a_idx', table_meta.indexes)
self.assertNotIn('b_idx', table_meta.indexes)
self.session.execute("CREATE INDEX a_idx ON %s (a)" % self.table_name)
self.session.execute("ALTER TABLE %s ADD b int" % self.table_name)
self.session.execute("CREATE INDEX b_idx ON %s (b)" % self.table_name)
ks_meta = self.cluster.metadata.keyspaces[self.keyspace_name]
table_meta = ks_meta.tables[self.table_name]
self.assertIsInstance(ks_meta.indexes['a_idx'], IndexMetadata)
self.assertIsInstance(ks_meta.indexes['b_idx'], IndexMetadata)
self.assertIsInstance(table_meta.indexes['a_idx'], IndexMetadata)
self.assertIsInstance(table_meta.indexes['b_idx'], IndexMetadata)
# both indexes updated when index dropped
self.session.execute("DROP INDEX a_idx")
ks_meta = self.cluster.metadata.keyspaces[self.keyspace_name]
table_meta = ks_meta.tables[self.table_name]
self.assertNotIn('a_idx', ks_meta.indexes)
{noformat}
Output:
{noformat}
AssertionError: 'a_idx' unexpectedly found in {u'b_idx':
<cassandra.metadata.IndexMetadata object at 0x7f2dd87d4590>, u'a_idx':
<cassandra.metadata.IndexMetadata object at 0x7f2dd87d4a10>}
{noformat}
> Table change response returns as keyspace change response
> ---------------------------------------------------------
>
> Key: CASSANDRA-9310
> URL: https://issues.apache.org/jira/browse/CASSANDRA-9310
> Project: Cassandra
> Issue Type: Bug
> Environment: C* 1.2.19 and 2.0.14 | python-driver master (upcoming v.
> 2.6)
> Reporter: Kishan Karunaratne
>
> When an index is dropped, its existence is still persisted across the
> keyspace metadata. This happens because the response to drop the index from
> the metadata is never received, as a keyspace change response is
> (incorrectly) received by the driver instead of a table change response.
> Test:
> {noformat}
> self.session.execute("CREATE TABLE %s (k int PRIMARY KEY, a int)" %
> self.table_name)
> ks_meta = self.cluster.metadata.keyspaces[self.keyspace_name]
> table_meta = ks_meta.tables[self.table_name]
> self.assertNotIn('a_idx', ks_meta.indexes)
> self.assertNotIn('b_idx', ks_meta.indexes)
> self.assertNotIn('a_idx', table_meta.indexes)
> self.assertNotIn('b_idx', table_meta.indexes)
> self.session.execute("CREATE INDEX a_idx ON %s (a)" % self.table_name)
> self.session.execute("ALTER TABLE %s ADD b int" % self.table_name)
> self.session.execute("CREATE INDEX b_idx ON %s (b)" % self.table_name)
> ks_meta = self.cluster.metadata.keyspaces[self.keyspace_name]
> table_meta = ks_meta.tables[self.table_name]
> self.assertIsInstance(ks_meta.indexes['a_idx'], IndexMetadata)
> self.assertIsInstance(ks_meta.indexes['b_idx'], IndexMetadata)
> self.assertIsInstance(table_meta.indexes['a_idx'], IndexMetadata)
> self.assertIsInstance(table_meta.indexes['b_idx'], IndexMetadata)
> # both indexes updated when index dropped
> self.session.execute("DROP INDEX a_idx")
> ks_meta = self.cluster.metadata.keyspaces[self.keyspace_name]
> table_meta = ks_meta.tables[self.table_name]
> self.assertNotIn('a_idx', ks_meta.indexes)
> {noformat}
> Output:
> {noformat}
> AssertionError: 'a_idx' unexpectedly found in {u'b_idx':
> <cassandra.metadata.IndexMetadata object at 0x7f2dd87d4590>, u'a_idx':
> <cassandra.metadata.IndexMetadata object at 0x7f2dd87d4a10>}
> {noformat}
> Debug log:
> {noformat}
> tests.integration: INFO: Using Cassandra version: 1.2.19
> tests.integration: DEBUG: Creating new ccm test_cluster cluster with
> {'version': '1.2.19'}
> tests.integration: DEBUG: Starting ccm test_cluster cluster
> cassandra.cluster: DEBUG: Connecting to cluster, contact points:
> ['127.0.0.1']; protocol version: 1
> cassandra.pool: DEBUG: Host 127.0.0.1 is now marked up
> cassandra.cluster: DEBUG: [control connection] Opening new connection to
> 127.0.0.1
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309742864976) to 127.0.0.1
> cassandra.io.libevreactor: DEBUG: Starting libev event loop
> cassandra.connection: DEBUG: Received options response on new connection
> (140309742864976) from 127.0.0.1
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309742864976) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309742864976) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309742864976) from 127.0.0.1
> cassandra.cluster: DEBUG: [control connection] Established new connection
> <LibevConnection(140309742864976) 127.0.0.1:9042>, registering watchers and
> refreshing schema and topology
> cassandra.cluster: DEBUG: [control connection] Refreshing node list and token
> map using preloaded results
> cassandra.cluster: DEBUG: [control connection] Found new host to connect to:
> 127.0.0.3
> cassandra.cluster: INFO: New Cassandra host <Host: 127.0.0.3 dc1> discovered
> cassandra.cluster: DEBUG: Handling new host <Host: 127.0.0.3 dc1> and
> notifying listeners
> cassandra.cluster: DEBUG: Done preparing queries for new host <Host:
> 127.0.0.3 dc1>
> cassandra.pool: DEBUG: Host 127.0.0.3 is now marked up
> cassandra.cluster: DEBUG: [control connection] Found new host to connect to:
> 127.0.0.2
> cassandra.cluster: INFO: New Cassandra host <Host: 127.0.0.2 dc1> discovered
> cassandra.cluster: DEBUG: Handling new host <Host: 127.0.0.2 dc1> and
> notifying listeners
> cassandra.cluster: DEBUG: Done preparing queries for new host <Host:
> 127.0.0.2 dc1>
> cassandra.pool: DEBUG: Host 127.0.0.2 is now marked up
> cassandra.cluster: DEBUG: [control connection] Finished fetching ring info
> cassandra.cluster: DEBUG: [control connection] Rebuilding token map due to
> topology changes
> cassandra.cluster: DEBUG: [control connection] Attempting to use preloaded
> results for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] triggers table not found
> cassandra.cluster: DEBUG: [control connection] user types table not found
> cassandra.cluster: DEBUG: [control connection] Fetched schema, rebuilding
> metadata
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.HintsColumnFamily
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.IndexInfo
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.LocationInfo
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.Migrations
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.NodeIdInfo
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.Schema
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.hints
> cassandra.cluster: DEBUG: Control connection created
> cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.3
> cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.2
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309742557904) to 127.0.0.2
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309743075024) to 127.0.0.3
> cassandra.connection: DEBUG: Received options response on new connection
> (140309743075024) from 127.0.0.3
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309743075024) 127.0.0.3:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309743075024) 127.0.0.3:9042>
> cassandra.connection: DEBUG: Received options response on new connection
> (140309742557904) from 127.0.0.2
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309742557904) 127.0.0.2:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309742557904) 127.0.0.2:9042>
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309743075024) from 127.0.0.3
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309742557904) from 127.0.0.2
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309742557200) to 127.0.0.2
> cassandra.connection: DEBUG: Received options response on new connection
> (140309742557200) from 127.0.0.2
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309742557200) 127.0.0.2:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309742557200) 127.0.0.2:9042>
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309742558608) to 127.0.0.3
> cassandra.connection: DEBUG: Received options response on new connection
> (140309742558608) from 127.0.0.3
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309742558608) 127.0.0.3:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309742558608) 127.0.0.3:9042>
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309742558608) from 127.0.0.3
> cassandra.pool: DEBUG: Finished initializing new connection pool for host
> 127.0.0.3
> cassandra.cluster: DEBUG: Added pool for host 127.0.0.3 to session
> cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.1
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309742559056) to 127.0.0.1
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309742557200) from 127.0.0.2
> cassandra.connection: DEBUG: Received options response on new connection
> (140309742559056) from 127.0.0.1
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309742559056) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309742559056) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309742559056) from 127.0.0.1
> cassandra.pool: DEBUG: Finished initializing new connection pool for host
> 127.0.0.2
> cassandra.cluster: DEBUG: Added pool for host 127.0.0.2 to session
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309742557840) to 127.0.0.1
> cassandra.connection: DEBUG: Received options response on new connection
> (140309742557840) from 127.0.0.1
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309742557840) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309742557840) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309742557840) from 127.0.0.1
> cassandra.pool: DEBUG: Finished initializing new connection pool for host
> 127.0.0.1
> cassandra.cluster: DEBUG: Added pool for host 127.0.0.1 to session
> cassandra.connection: DEBUG: Message pushed from server:
> <EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
> event_args={'keyspace': u'test3rf', 'change_type': u'CREATED', 'table': u''},
> trace_id=None)>
> cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
> Keyspace: test3rf; Table: , Type: None
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
> test3rf, rebuilding metadata
> cassandra.connection: DEBUG: Message pushed from server:
> <EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
> event_args={'keyspace': u'test2rf', 'change_type': u'CREATED', 'table': u''},
> trace_id=None)>
> cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
> Keyspace: test2rf; Table: , Type: None
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
> test2rf, rebuilding metadata
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
> test3rf, rebuilding metadata
> cassandra.connection: DEBUG: Message pushed from server:
> <EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
> event_args={'keyspace': u'test1rf', 'change_type': u'CREATED', 'table': u''},
> trace_id=None)>
> cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
> Keyspace: test1rf; Table: , Type: None
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
> test1rf, rebuilding metadata
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
> test2rf, rebuilding metadata
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
> test1rf, rebuilding metadata
> cassandra.connection: DEBUG: Message pushed from server:
> <EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
> event_args={'keyspace': u'test3rf', 'change_type': u'CREATED', 'table':
> u'test'}, trace_id=None)>
> cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
> Keyspace: test3rf; Table: test, Type: None
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched table info for
> test3rf.test, rebuilding metadata
> cassandra.cluster: DEBUG: Shutting down Cluster Scheduler
> cassandra.cluster: DEBUG: Shutting down control connection
> cassandra.io.libevreactor: DEBUG: Closing connection (140309742864976) to
> 127.0.0.1
> cassandra.cluster: DEBUG: Not executing scheduled task due to Scheduler
> shutdown
> cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.1
> cassandra.io.libevreactor: DEBUG: Closing connection (140309743075024) to
> 127.0.0.3
> cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.3
> cassandra.io.libevreactor: DEBUG: Closing connection (140309742558608) to
> 127.0.0.3
> cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.3
> cassandra.io.libevreactor: DEBUG: Closing connection (140309742557904) to
> 127.0.0.2
> cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.2
> cassandra.io.libevreactor: DEBUG: Closing connection (140309742557200) to
> 127.0.0.2
> cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.2
> cassandra.io.libevreactor: DEBUG: Closing connection (140309742559056) to
> 127.0.0.1
> cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.1
> cassandra.io.libevreactor: DEBUG: Closing connection (140309742557840) to
> 127.0.0.1
> cassandra.io.libevreactor: DEBUG: Closed socket to 127.0.0.1
> cassandra.io.libevreactor: DEBUG: All Connections currently closed, event
> loop ended
> cassandra.cluster: DEBUG: Connecting to cluster, contact points:
> ['127.0.0.1']; protocol version: 1
> cassandra.pool: DEBUG: Host 127.0.0.1 is now marked up
> cassandra.cluster: DEBUG: [control connection] Opening new connection to
> 127.0.0.1
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309742559120) to 127.0.0.1
> cassandra.io.libevreactor: DEBUG: Starting libev event loop
> cassandra.connection: DEBUG: Received options response on new connection
> (140309742559120) from 127.0.0.1
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309742559120) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309742559120) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309742559120) from 127.0.0.1
> cassandra.cluster: DEBUG: [control connection] Established new connection
> <LibevConnection(140309742559120) 127.0.0.1:9042>, registering watchers and
> refreshing schema and topology
> cassandra.cluster: DEBUG: [control connection] Refreshing node list and token
> map using preloaded results
> cassandra.cluster: DEBUG: [control connection] Found new host to connect to:
> 127.0.0.3
> cassandra.cluster: INFO: New Cassandra host <Host: 127.0.0.3 dc1> discovered
> cassandra.cluster: DEBUG: Handling new host <Host: 127.0.0.3 dc1> and
> notifying listeners
> cassandra.cluster: DEBUG: Done preparing queries for new host <Host:
> 127.0.0.3 dc1>
> cassandra.pool: DEBUG: Host 127.0.0.3 is now marked up
> cassandra.cluster: DEBUG: [control connection] Found new host to connect to:
> 127.0.0.2
> cassandra.cluster: INFO: New Cassandra host <Host: 127.0.0.2 dc1> discovered
> cassandra.cluster: DEBUG: Handling new host <Host: 127.0.0.2 dc1> and
> notifying listeners
> cassandra.cluster: DEBUG: Done preparing queries for new host <Host:
> 127.0.0.2 dc1>
> cassandra.pool: DEBUG: Host 127.0.0.2 is now marked up
> cassandra.cluster: DEBUG: [control connection] Finished fetching ring info
> cassandra.cluster: DEBUG: [control connection] Rebuilding token map due to
> topology changes
> cassandra.cluster: DEBUG: [control connection] Attempting to use preloaded
> results for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] triggers table not found
> cassandra.cluster: DEBUG: [control connection] user types table not found
> cassandra.cluster: DEBUG: [control connection] Fetched schema, rebuilding
> metadata
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.HintsColumnFamily
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.IndexInfo
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.LocationInfo
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.Migrations
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.NodeIdInfo
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.Schema
> cassandra.metadata: WARNING: Building table metadata with no column meta for
> system.hints
> cassandra.cluster: DEBUG: Control connection created
> cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.3
> cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.2
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309700367952) to 127.0.0.2
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309742595920) to 127.0.0.3
> cassandra.connection: DEBUG: Received options response on new connection
> (140309700367952) from 127.0.0.2
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309700367952) 127.0.0.2:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309700367952) 127.0.0.2:9042>
> cassandra.connection: DEBUG: Received options response on new connection
> (140309742595920) from 127.0.0.3
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309742595920) 127.0.0.3:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309742595920) 127.0.0.3:9042>
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309700367952) from 127.0.0.2
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309742595920) from 127.0.0.3
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309742595856) to 127.0.0.3
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309700368784) to 127.0.0.2
> cassandra.connection: DEBUG: Received options response on new connection
> (140309742595856) from 127.0.0.3
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309742595856) 127.0.0.3:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309742595856) 127.0.0.3:9042>
> cassandra.connection: DEBUG: Received options response on new connection
> (140309700368784) from 127.0.0.2
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309700368784) 127.0.0.2:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309700368784) 127.0.0.2:9042>
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309742595856) from 127.0.0.3
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309700368784) from 127.0.0.2
> cassandra.pool: DEBUG: Finished initializing new connection pool for host
> 127.0.0.3
> cassandra.cluster: DEBUG: Added pool for host 127.0.0.3 to session
> cassandra.pool: DEBUG: Initializing new connection pool for host 127.0.0.1
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309700369232) to 127.0.0.1
> cassandra.pool: DEBUG: Finished initializing new connection pool for host
> 127.0.0.2
> cassandra.cluster: DEBUG: Added pool for host 127.0.0.2 to session
> cassandra.connection: DEBUG: Received options response on new connection
> (140309700369232) from 127.0.0.1
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309700369232) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309700369232) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309700369232) from 127.0.0.1
> cassandra.connection: DEBUG: Sending initial options message for new
> connection (140309700367888) to 127.0.0.1
> cassandra.connection: DEBUG: Received options response on new connection
> (140309700367888) from 127.0.0.1
> cassandra.connection: DEBUG: Sending StartupMessage on
> <LibevConnection(140309700367888) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Sent StartupMessage on
> <LibevConnection(140309700367888) 127.0.0.1:9042>
> cassandra.connection: DEBUG: Got ReadyMessage on new connection
> (140309700367888) from 127.0.0.1
> cassandra.pool: DEBUG: Finished initializing new connection pool for host
> 127.0.0.1
> cassandra.cluster: DEBUG: Added pool for host 127.0.0.1 to session
> cassandra.connection: DEBUG: Message pushed from server:
> <EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
> event_args={'keyspace': u'index_map_tests', 'change_type': u'CREATED',
> 'table': u''}, trace_id=None)>
> cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
> Keyspace: index_map_tests; Table: , Type: None
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
> index_map_tests, rebuilding metadata
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
> index_map_tests, rebuilding metadata
> cassandra.connection: DEBUG: Message pushed from server:
> <EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
> event_args={'keyspace': u'index_map_tests', 'change_type': u'CREATED',
> 'table': u'test_index_updates'}, trace_id=None)>
> cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
> Keyspace: index_map_tests; Table: test_index_updates, Type: None
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched table info for
> index_map_tests.test_index_updates, rebuilding metadata
> cassandra.connection: DEBUG: Message pushed from server:
> <EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
> event_args={'keyspace': u'index_map_tests', 'change_type': u'UPDATED',
> 'table': u'test_index_updates'}, trace_id=None)>
> cassandra.cluster: DEBUG: Ignoring schedule_unique for already-scheduled
> task: (<bound method ControlConnection.refresh_schema of
> <cassandra.cluster.ControlConnection object at 0x7f9c6864fc90>>,
> (u'index_map_tests', u'test_index_updates', None))
> cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
> Keyspace: index_map_tests; Table: test_index_updates, Type: None
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched table info for
> index_map_tests.test_index_updates, rebuilding metadata
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched table info for
> index_map_tests.test_index_updates, rebuilding metadata
> cassandra.connection: DEBUG: Message pushed from server:
> <EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
> event_args={'keyspace': u'index_map_tests', 'change_type': u'UPDATED',
> 'table': u'test_index_updates'}, trace_id=None)>
> cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
> Keyspace: index_map_tests; Table: test_index_updates, Type: None
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched table info for
> index_map_tests.test_index_updates, rebuilding metadata
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched table info for
> index_map_tests.test_index_updates, rebuilding metadata
> cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
> Keyspace: index_map_tests; Table: test_index_updates, Type: None
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.connection: DEBUG: Message pushed from server:
> <EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
> event_args={'keyspace': u'index_map_tests', 'change_type': u'UPDATED',
> 'table': u'test_index_updates'}, trace_id=None)>
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched table info for
> index_map_tests.test_index_updates, rebuilding metadata
> cassandra.cluster: DEBUG: [control connection] Fetched table info for
> index_map_tests.test_index_updates, rebuilding metadata
> cassandra.connection: DEBUG: Message pushed from server:
> <EventMessage(stream_id=-1, event_type=u'SCHEMA_CHANGE',
> event_args={'keyspace': u'index_map_tests', 'change_type': u'UPDATED',
> 'table': u'test_index_updates'}, trace_id=None)>
> cassandra.cluster: DEBUG: Refreshing schema in response to schema change.
> Keyspace: index_map_tests; Table: , Type: None
> cassandra.cluster: DEBUG: [control connection] Waiting for schema agreement
> cassandra.cluster: DEBUG: [control connection] Schemas mismatched, trying
> again
> cassandra.cluster: DEBUG: [control connection] Schemas match
> cassandra.cluster: DEBUG: [control connection] Fetched keyspace info for
> index_map_tests, rebuilding metadata
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
