17:17:05,920 urllib3.connectionpool DEBUG connectionpool.py:1014 | Starting new HTTPS connection (1): s3.amazonaws.com:443 17:17:06,506 urllib3.connectionpool DEBUG connectionpool.py:473 | https://s3.amazonaws.com:443 "GET /downloads.scylladb.com?prefix=downloads%2Fscylla-enterprise%2Frelocatable%2Fscylladb-2023.1&encoding-type=url HTTP/1.1" 200 None 17:17:10,887 urllib3.connectionpool DEBUG connectionpool.py:1014 | Starting new HTTPS connection (1): s3.amazonaws.com:443 17:17:11,460 urllib3.connectionpool DEBUG connectionpool.py:473 | https://s3.amazonaws.com:443 "GET /downloads.scylladb.com?prefix=downloads%2Fscylla-enterprise%2Frelocatable%2Fscylladb-2023.1&encoding-type=url HTTP/1.1" 200 None 17:17:16,888 urllib3.connectionpool DEBUG connectionpool.py:1014 | Starting new HTTPS connection (1): s3.amazonaws.com:443 17:17:17,511 urllib3.connectionpool DEBUG connectionpool.py:473 | https://s3.amazonaws.com:443 "GET /downloads.scylladb.com?prefix=downloads%2Fscylla-enterprise%2Frelocatable%2Fscylladb-2023.1&encoding-type=url HTTP/1.1" 200 None 17:17:21,943 conftest INFO conftest.py :252 | Starting execution of test_add_udt_to_another_data_types at 2023-09-26 17:17:21.943406 17:17:21,944 dtest_setup INFO dtest_setup.py :783 | cluster ccm directory: /home/jancio/.dtest/dtest-eqso2zue 17:17:21,996 urllib3.connectionpool DEBUG connectionpool.py:1014 | Starting new HTTPS connection (1): s3.amazonaws.com:443 17:17:22,682 urllib3.connectionpool DEBUG connectionpool.py:473 | https://s3.amazonaws.com:443 "GET /downloads.scylladb.com?prefix=downloads%2Fscylla-enterprise%2Frelocatable%2Fscylladb-2023.1&encoding-type=url HTTP/1.1" 200 None 17:17:27,267 ccm DEBUG cluster.py :709 | Started cluster 'test' version 2023.1.1 installed in /home/jancio/.ccm/scylla-repository/release/2023.1.1 17:17:27,267 dtest_setup DEBUG dtest_setup.py :691 | Scylla mode is 'release' 17:17:27,267 dtest_setup DEBUG dtest_setup.py :692 | Cluster *_request_timeout_in_ms=10000, range_request_timeout_in_ms=30000, cql request_timeout=30 17:17:27,272 dtest_setup DEBUG dtest_setup.py :751 | Done setting configuration options: { 'cas_contention_timeout_in_ms': 10000, 'consistent_cluster_management': False, 'counter_write_request_timeout_in_ms': 20000, 'initial_token': None, 'num_tokens': 256, 'phi_convict_threshold': 5, 'range_request_timeout_in_ms': 30000, 'read_request_timeout_in_ms': 10000, 'request_timeout_in_ms': 10000, 'ring_delay_ms': 10000, 'skip_wait_for_gossip_to_settle': 0, 'task_ttl_in_seconds': 0, 'truncate_request_timeout_in_ms': 30000, 'write_request_timeout_in_ms': 10000} 17:17:27,275 dtest_setup DEBUG dtest_setup.py :61 | Allocated cluster ID 89: /home/jancio/.dtest/dtest-eqso2zue ------------------------------ Captured log call ------------------------------- 17:17:27,380 ccm DEBUG cluster.py :709 | start_nodes: no_wait=False wait_for_binary_proto=True wait_other_notice=True force_wait_for_cluster_start=True 17:17:27,383 ccm DEBUG cluster.py :709 | node1: Starting scylla: args=['/home/jancio/.dtest/dtest-eqso2zue/test/node1/bin/scylla', '--options-file', '/home/jancio/.dtest/dtest-eqso2zue/test/node1/conf/scylla.yaml', '--log-to-stdout', '1', '--api-address', '127.0.89.1', '--collectd-hostname', 'janciolap.node1', '--smp', '2', '--memory', '1024M', '--developer-mode', 'true', '--default-log-level', 'info', '--collectd', '0', '--overprovisioned', '--prometheus-address', '127.0.89.1', '--unsafe-bypass-fsync', '1', '--kernel-page-cache', '1', '--commitlog-use-o-dsync', '0', '--max-networking-io-control-blocks', '1000'] wait_other_notice=True wait_for_binary_proto=True 17:17:27,708 ccm DEBUG cluster.py :709 | node1: Starting scylla-jmx: args=['/home/jancio/.dtest/dtest-eqso2zue/test/node1/bin/symlinks/scylla-jmx', '-Dapiaddress=127.0.89.1', '-Djavax.management.builder.initial=com.scylladb.jmx.utils.APIBuilder', '-Djava.rmi.server.hostname=127.0.89.1', '-Dcom.sun.management.jmxremote', '-Dcom.sun.management.jmxremote.host=127.0.89.1', '-Dcom.sun.management.jmxremote.port=7199', '-Dcom.sun.management.jmxremote.rmi.port=7199', '-Dcom.sun.management.jmxremote.local.only=false', '-Xmx256m', '-XX:+UseSerialGC', '-Dcom.sun.management.jmxremote.authenticate=false', '-Dcom.sun.management.jmxremote.ssl=false', '-jar', '/home/jancio/.dtest/dtest-eqso2zue/test/node1/bin/scylla-jmx-1.0.jar'] 17:17:27,965 ccm DEBUG cluster.py :709 | node2: Starting scylla: args=['/home/jancio/.dtest/dtest-eqso2zue/test/node2/bin/scylla', '--options-file', '/home/jancio/.dtest/dtest-eqso2zue/test/node2/conf/scylla.yaml', '--log-to-stdout', '1', '--api-address', '127.0.89.2', '--collectd-hostname', 'janciolap.node2', '--smp', '2', '--memory', '1024M', '--developer-mode', 'true', '--default-log-level', 'info', '--collectd', '0', '--overprovisioned', '--prometheus-address', '127.0.89.2', '--unsafe-bypass-fsync', '1', '--kernel-page-cache', '1', '--commitlog-use-o-dsync', '0', '--max-networking-io-control-blocks', '1000'] wait_other_notice=True wait_for_binary_proto=True 17:17:30,650 ccm DEBUG cluster.py :709 | node2: Starting scylla-jmx: args=['/home/jancio/.dtest/dtest-eqso2zue/test/node2/bin/symlinks/scylla-jmx', '-Dapiaddress=127.0.89.2', '-Djavax.management.builder.initial=com.scylladb.jmx.utils.APIBuilder', '-Djava.rmi.server.hostname=127.0.89.2', '-Dcom.sun.management.jmxremote', '-Dcom.sun.management.jmxremote.host=127.0.89.2', '-Dcom.sun.management.jmxremote.port=7199', '-Dcom.sun.management.jmxremote.rmi.port=7199', '-Dcom.sun.management.jmxremote.local.only=false', '-Xmx256m', '-XX:+UseSerialGC', '-Dcom.sun.management.jmxremote.authenticate=false', '-Dcom.sun.management.jmxremote.ssl=false', '-jar', '/home/jancio/.dtest/dtest-eqso2zue/test/node2/bin/scylla-jmx-1.0.jar'] 17:17:30,960 ccm DEBUG cluster.py :709 | node3: Starting scylla: args=['/home/jancio/.dtest/dtest-eqso2zue/test/node3/bin/scylla', '--options-file', '/home/jancio/.dtest/dtest-eqso2zue/test/node3/conf/scylla.yaml', '--log-to-stdout', '1', '--api-address', '127.0.89.3', '--collectd-hostname', 'janciolap.node3', '--smp', '2', '--memory', '1024M', '--developer-mode', 'true', '--default-log-level', 'info', '--collectd', '0', '--overprovisioned', '--prometheus-address', '127.0.89.3', '--unsafe-bypass-fsync', '1', '--kernel-page-cache', '1', '--commitlog-use-o-dsync', '0', '--max-networking-io-control-blocks', '1000'] wait_other_notice=True wait_for_binary_proto=True 17:17:33,155 ccm DEBUG cluster.py :709 | node3: Starting scylla-jmx: args=['/home/jancio/.dtest/dtest-eqso2zue/test/node3/bin/symlinks/scylla-jmx', '-Dapiaddress=127.0.89.3', '-Djavax.management.builder.initial=com.scylladb.jmx.utils.APIBuilder', '-Djava.rmi.server.hostname=127.0.89.3', '-Dcom.sun.management.jmxremote', '-Dcom.sun.management.jmxremote.host=127.0.89.3', '-Dcom.sun.management.jmxremote.port=7199', '-Dcom.sun.management.jmxremote.rmi.port=7199', '-Dcom.sun.management.jmxremote.local.only=false', '-Xmx256m', '-XX:+UseSerialGC', '-Dcom.sun.management.jmxremote.authenticate=false', '-Dcom.sun.management.jmxremote.ssl=false', '-jar', '/home/jancio/.dtest/dtest-eqso2zue/test/node3/bin/scylla-jmx-1.0.jar'] 17:17:33,425 cassandra.cluster DEBUG dtest_setup.py :434 | Connecting to cluster, contact points: ['127.0.89.1']; protocol version: 4 17:17:33,425 cassandra.pool DEBUG dtest_setup.py :434 | Host 127.0.89.1:9042 is now marked up 17:17:33,425 cassandra.cluster DEBUG dtest_setup.py :434 | [control connection] Opening new connection to 127.0.89.1:9042 17:17:33,426 cassandra.connection DEBUG libevreactor.py:267 | Connection 139996771306640 127.0.0.1:39652 -> 127.0.89.1:9042 17:17:33,426 cassandra.connection DEBUG libevreactor.py:274 | Sending initial options message for new connection (139996771306640) to 127.0.89.1:9042 17:17:33,426 cassandra.io.libevreactor DEBUG libevreactor.py:87 | Starting libev event loop 17:17:33,427 cassandra.connection DEBUG libevreactor.py:370 | Received options response on new connection (139996771306640) from 127.0.89.1:9042 17:17:33,427 cassandra.connection DEBUG libevreactor.py:370 | No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['lz4', 'snappy'] 17:17:33,427 cassandra.connection DEBUG libevreactor.py:370 | Sending StartupMessage on 17:17:33,427 cassandra.connection DEBUG libevreactor.py:370 | Sent StartupMessage on 17:17:33,427 cassandra.connection DEBUG libevreactor.py:370 | Got ReadyMessage on new connection (139996771306640) from 127.0.89.1:9042 17:17:33,427 cassandra.cluster DEBUG dtest_setup.py :434 | [control connection] Established new connection , registering watchers and refreshing schema and topology 17:17:33,429 cassandra.cluster DEBUG dtest_setup.py :434 | [control connection] Refreshing node list and token map using preloaded results 17:17:33,429 cassandra.policies INFO policies.py :289 | Using datacenter 'datacenter1' for DCAwareRoundRobinPolicy (via host '127.0.89.1:9042'); if incorrect, please specify a local_dc to the constructor, or limit contact points to local cluster nodes 17:17:33,429 cassandra.cluster DEBUG dtest_setup.py :434 | [control connection] Found new host to connect to: 127.0.89.2:9042 17:17:33,430 cassandra.cluster INFO dtest_setup.py :434 | New Cassandra host discovered 17:17:33,430 cassandra.cluster DEBUG dtest_setup.py :434 | Handling new host and notifying listeners 17:17:33,430 cassandra.cluster DEBUG dtest_setup.py :434 | Done preparing queries for new host 17:17:33,430 cassandra.pool DEBUG dtest_setup.py :434 | Host 127.0.89.2:9042 is now marked up 17:17:33,430 cassandra.cluster DEBUG dtest_setup.py :434 | [control connection] Found new host to connect to: 127.0.89.3:9042 17:17:33,430 cassandra.cluster INFO dtest_setup.py :434 | New Cassandra host discovered 17:17:33,430 cassandra.cluster DEBUG dtest_setup.py :434 | Handling new host and notifying listeners 17:17:33,430 cassandra.cluster DEBUG dtest_setup.py :434 | Done preparing queries for new host 17:17:33,430 cassandra.pool DEBUG dtest_setup.py :434 | Host 127.0.89.3:9042 is now marked up 17:17:33,430 cassandra.cluster DEBUG dtest_setup.py :434 | [control connection] Removing host not found in peers metadata: 17:17:33,430 cassandra.cluster DEBUG dtest_setup.py :434 | [control connection] Finished fetching ring info 17:17:33,430 cassandra.cluster DEBUG dtest_setup.py :434 | [control connection] Rebuilding token map due to topology changes 17:17:33,437 cassandra.cluster DEBUG dtest_setup.py :434 | Control connection created 17:17:33,437 cassandra.pool DEBUG thread.py :58 | Initializing connection for host 127.0.89.1:9042 17:17:33,438 cassandra.pool DEBUG thread.py :58 | Initializing connection for host 127.0.89.2:9042 17:17:33,438 cassandra.connection DEBUG libevreactor.py:267 | Connection 139996779874256 127.0.0.1:39654 -> 127.0.89.1:9042 17:17:33,438 cassandra.connection DEBUG libevreactor.py:274 | Sending initial options message for new connection (139996779874256) to 127.0.89.1:9042 17:17:33,438 cassandra.connection DEBUG libevreactor.py:267 | Connection 139996779873040 127.0.0.1:58288 -> 127.0.89.2:9042 17:17:33,438 cassandra.connection DEBUG libevreactor.py:274 | Sending initial options message for new connection (139996779873040) to 127.0.89.2:9042 17:17:33,438 cassandra.connection DEBUG libevreactor.py:370 | Received options response on new connection (139996779874256) from 127.0.89.1:9042 17:17:33,438 cassandra.connection DEBUG libevreactor.py:370 | No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['lz4', 'snappy'] 17:17:33,438 cassandra.connection DEBUG libevreactor.py:370 | Sending StartupMessage on 17:17:33,438 cassandra.connection DEBUG libevreactor.py:370 | Sent StartupMessage on 17:17:33,439 cassandra.connection DEBUG libevreactor.py:370 | Got ReadyMessage on new connection (139996779874256) from 127.0.89.1:9042 17:17:33,439 cassandra.connection DEBUG libevreactor.py:370 | Received options response on new connection (139996779873040) from 127.0.89.2:9042 17:17:33,439 cassandra.pool DEBUG thread.py :58 | First connection created to 127.0.89.1:9042 for shard_id=1 17:17:33,439 cassandra.connection DEBUG libevreactor.py:370 | No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['lz4', 'snappy'] 17:17:33,439 cassandra.pool DEBUG thread.py :58 | Finished initializing connection for host 127.0.89.1:9042 17:17:33,439 cassandra.connection DEBUG libevreactor.py:370 | Sending StartupMessage on 17:17:33,439 cassandra.cluster DEBUG thread.py :58 | Added pool for host 127.0.89.1:9042 to session 17:17:33,439 cassandra.connection DEBUG libevreactor.py:370 | Sent StartupMessage on 17:17:33,439 cassandra.pool DEBUG thread.py :58 | Initializing connection for host 127.0.89.3:9042 17:17:33,439 cassandra.connection DEBUG libevreactor.py:370 | Got ReadyMessage on new connection (139996779873040) from 127.0.89.2:9042 17:17:33,440 cassandra.pool DEBUG thread.py :58 | First connection created to 127.0.89.2:9042 for shard_id=0 17:17:33,440 cassandra.pool DEBUG thread.py :58 | Finished initializing connection for host 127.0.89.2:9042 17:17:33,440 cassandra.cluster DEBUG thread.py :58 | Added pool for host 127.0.89.2:9042 to session 17:17:33,440 cassandra.connection DEBUG libevreactor.py:267 | Connection 139996785115088 127.0.0.1:54294 -> 127.0.89.3:9042 17:17:33,440 cassandra.pool DEBUG thread.py :58 | shard_aware_endpoint= 17:17:33,440 cassandra.connection DEBUG libevreactor.py:274 | Sending initial options message for new connection (139996785115088) to 127.0.89.3:9042 17:17:33,440 cassandra.connection DEBUG libevreactor.py:267 | connection (139996785990672) port=63954 should be shard_id=0 17:17:33,440 cassandra.connection DEBUG libevreactor.py:267 | Connection 139996785990672 127.0.0.1:63954 -> 127.0.89.1:19042 17:17:33,440 cassandra.connection DEBUG libevreactor.py:370 | Received options response on new connection (139996785115088) from 127.0.89.3:9042 17:17:33,440 cassandra.connection DEBUG libevreactor.py:274 | Sending initial options message for new connection (139996785990672) to 127.0.89.1:19042 17:17:33,440 cassandra.connection DEBUG libevreactor.py:370 | No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['lz4', 'snappy'] 17:17:33,441 cassandra.connection DEBUG libevreactor.py:370 | Sending StartupMessage on 17:17:33,441 cassandra.connection DEBUG libevreactor.py:370 | Sent StartupMessage on 17:17:33,441 cassandra.connection DEBUG libevreactor.py:370 | Got ReadyMessage on new connection (139996785115088) from 127.0.89.3:9042 17:17:33,441 cassandra.pool DEBUG thread.py :58 | First connection created to 127.0.89.3:9042 for shard_id=0 17:17:33,441 cassandra.connection DEBUG libevreactor.py:370 | Received options response on new connection (139996785990672) from 127.0.89.1:19042 17:17:33,441 cassandra.pool DEBUG thread.py :58 | Finished initializing connection for host 127.0.89.3:9042 17:17:33,441 cassandra.connection DEBUG libevreactor.py:370 | No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['lz4', 'snappy'] 17:17:33,441 cassandra.cluster DEBUG thread.py :58 | Added pool for host 127.0.89.3:9042 to session 17:17:33,441 cassandra.connection DEBUG libevreactor.py:370 | Sending StartupMessage on 17:17:33,442 cassandra.pool DEBUG thread.py :58 | shard_aware_endpoint= 17:17:33,442 cassandra.cluster DEBUG dtest_setup.py :434 | Not starting MonitorReporter thread for Insights; not supported by server version 3.0.8 on ControlConnection host 127.0.89.1:9042 17:17:33,442 cassandra.connection DEBUG libevreactor.py:370 | Sent StartupMessage on 17:17:33,442 cassandra.cluster DEBUG dtest_setup.py :434 | Started Session with client_id 3103d181-8059-4b33-ae2f-b04c392de5cb and session_id 7dd64c86-5b9e-421b-903e-9b77903ca695 17:17:33,442 cassandra.connection DEBUG libevreactor.py:267 | connection (139996782357136) port=56709 should be shard_id=1 17:17:33,442 cassandra.connection DEBUG libevreactor.py:370 | Got ReadyMessage on new connection (139996785990672) from 127.0.89.1:19042 17:17:33,442 cassandra.pool DEBUG thread.py :58 | Received a connection 139996785990672 for shard_id=0 on host 127.0.89.1:9042 17:17:33,442 cassandra.connection DEBUG libevreactor.py:267 | Connection 139996782357136 127.0.0.1:56709 -> 127.0.89.2:19042 17:17:33,443 cassandra.pool DEBUG thread.py :58 | New connection (139996785990672) created to shard_id=0 on host 127.0.89.1:9042 17:17:33,443 cassandra.connection DEBUG libevreactor.py:274 | Sending initial options message for new connection (139996782357136) to 127.0.89.2:19042 17:17:33,443 cassandra.pool DEBUG thread.py :58 | Connected to 2/2 shards on host 127.0.89.1:9042 (0 missing or needs replacement) 17:17:33,443 cassandra.pool DEBUG thread.py :58 | All shards of host 127.0.89.1:9042 have at least one connection, closing 0 excess connections 17:17:33,443 cassandra.pool DEBUG thread.py :58 | shard_aware_endpoint= 17:17:33,443 cassandra.connection DEBUG libevreactor.py:370 | Received options response on new connection (139996782357136) from 127.0.89.2:19042 17:17:33,444 cassandra.connection DEBUG libevreactor.py:370 | No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['lz4', 'snappy'] 17:17:33,444 cassandra.connection DEBUG libevreactor.py:267 | connection (139996782348688) port=57047 should be shard_id=1 17:17:33,444 cassandra.connection DEBUG libevreactor.py:370 | Sending StartupMessage on 17:17:33,444 cassandra.connection DEBUG libevreactor.py:370 | Sent StartupMessage on 17:17:33,444 cassandra.connection DEBUG libevreactor.py:267 | Connection 139996782348688 127.0.0.1:57047 -> 127.0.89.3:19042 17:17:33,444 cassandra.connection DEBUG libevreactor.py:370 | Got ReadyMessage on new connection (139996782357136) from 127.0.89.2:19042 17:17:33,444 cassandra.connection DEBUG libevreactor.py:274 | Sending initial options message for new connection (139996782348688) to 127.0.89.3:19042 17:17:33,444 cassandra.pool DEBUG thread.py :58 | Received a connection 139996782357136 for shard_id=1 on host 127.0.89.2:9042 17:17:33,444 cassandra.pool DEBUG thread.py :58 | New connection (139996782357136) created to shard_id=1 on host 127.0.89.2:9042 17:17:33,445 cassandra.pool DEBUG thread.py :58 | Connected to 2/2 shards on host 127.0.89.2:9042 (0 missing or needs replacement) 17:17:33,445 cassandra.pool DEBUG thread.py :58 | All shards of host 127.0.89.2:9042 have at least one connection, closing 0 excess connections 17:17:33,445 cassandra.connection DEBUG libevreactor.py:370 | Received options response on new connection (139996782348688) from 127.0.89.3:19042 17:17:33,445 cassandra.connection DEBUG libevreactor.py:370 | No available compression types supported on both ends. locally supported: odict_keys([]). remotely supported: ['lz4', 'snappy'] 17:17:33,445 cassandra.connection DEBUG libevreactor.py:370 | Sending StartupMessage on 17:17:33,445 cassandra.connection DEBUG libevreactor.py:370 | Sent StartupMessage on 17:17:33,445 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:33,446 cassandra.connection DEBUG libevreactor.py:370 | Got ReadyMessage on new connection (139996782348688) from 127.0.89.3:19042 17:17:33,446 cassandra.pool DEBUG thread.py :58 | Received a connection 139996782348688 for shard_id=1 on host 127.0.89.3:9042 17:17:33,446 cassandra.pool DEBUG thread.py :58 | New connection (139996782348688) created to shard_id=1 on host 127.0.89.3:9042 17:17:33,446 cassandra.pool DEBUG thread.py :58 | Connected to 2/2 shards on host 127.0.89.3:9042 (0 missing or needs replacement) 17:17:33,446 cassandra.pool DEBUG thread.py :58 | All shards of host 127.0.89.3:9042 have at least one connection, closing 0 excess connections 17:17:33,448 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'KEYSPACE', 'change_type': 'CREATED', 'keyspace': 'abcinfo'} 17:17:33,448 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:33,449 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:33,650 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:33,854 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:34,058 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:34,263 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:34,266 cassandra.cluster DEBUG dtest_class.py :193 | [control connection] Waiting for schema agreement 17:17:34,269 cassandra.cluster DEBUG dtest_class.py :193 | [control connection] Schemas mismatched, trying again 17:17:34,473 cassandra.cluster DEBUG dtest_class.py :193 | [control connection] Schemas mismatched, trying again 17:17:34,675 cassandra.cluster DEBUG dtest_class.py :193 | [control connection] Schemas match 17:17:34,675 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:34,676 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1050 | Create user_refs type 17:17:34,676 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:34,677 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:34,680 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TYPE', 'change_type': 'CREATED', 'keyspace': 'abcinfo', 'type': 'user_refs'} 17:17:34,680 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:34,680 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:34,884 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:35,089 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:35,293 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:35,296 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1054 | Create obs_entity type 17:17:35,300 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:35,306 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TYPE', 'change_type': 'CREATED', 'keyspace': 'abcinfo', 'type': 'obs_entity'} 17:17:35,306 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:35,307 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:35,511 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:35,715 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:35,919 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:36,123 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:36,328 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:36,329 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:36,331 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1058 | Create other_entity type 17:17:36,333 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:36,336 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:36,537 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:36,739 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:36,943 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:37,147 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:37,148 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:37,150 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TYPE', 'change_type': 'CREATED', 'keyspace': 'abcinfo', 'type': 'other_entity'} 17:17:37,152 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:37,153 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:37,158 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:37,159 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:37,162 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1062 | Create entity table 17:17:37,164 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:37,176 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:37,180 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TABLE', 'change_type': 'CREATED', 'keyspace': 'abcinfo', 'table': 'entity'} 17:17:37,180 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:37,181 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:37,385 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:37,589 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:37,794 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:37,998 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:38,202 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:38,407 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:38,611 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:38,612 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:38,620 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:38,620 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1070 | Create index on entity(service) 17:17:38,624 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:38,625 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:38,630 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TABLE', 'change_type': 'UPDATED', 'keyspace': 'abcinfo', 'table': 'entity'} 17:17:38,630 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:38,630 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:38,832 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:39,036 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:39,240 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:39,248 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1073 | Create index on entity(type) 17:17:39,259 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:39,259 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:39,259 cassandra.cluster DEBUG libevreactor.py:370 | Ignoring schedule_unique for already-scheduled task: (>, (), (('target_type', 'TABLE'), ('change_type', 'UPDATED'), ('keyspace', 'abcinfo'), ('table', 'entity'))) 17:17:39,265 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TABLE', 'change_type': 'UPDATED', 'keyspace': 'abcinfo', 'table': 'entity'} 17:17:39,265 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:39,266 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:39,470 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:39,674 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:39,879 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:40,083 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:40,288 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:40,289 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:40,297 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:40,297 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1076 | Create entity_by_type materialized view 17:17:40,297 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:40,301 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:40,301 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:40,303 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:40,304 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:40,304 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:40,307 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TABLE', 'change_type': 'CREATED', 'keyspace': 'abcinfo', 'table': 'entity_by_type'} 17:17:40,307 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:40,307 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:40,511 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:40,715 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:40,917 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:41,119 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:41,323 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:41,324 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:41,333 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:41,333 tools.tables_view_manager DEBUG tables_view_manager.py:682 | Waiting for view abcinfo.entity_by_type to finish building: num_nodes=3 num_alive=3 cl=QUORUM 17:17:41,335 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:41,339 tools.tables_view_manager DEBUG tables_view_manager.py:693 | wait_for_view abcinfo.entity_by_type: status=defaultdict(, {'SUCCESS': {UUID('836cf1c5-7620-4c1b-a003-1e26c0378c95'), UUID('0816e4d5-7157-4010-9868-b971be0f1b70'), UUID('86d4a01a-a6ed-4aa0-954d-3e325c89b739')}}) 17:17:41,344 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:41,355 ccm DEBUG cluster.py :709 | node1: nodetool cmd=info wait=True timeout=60 17:17:42,322 ccm DEBUG cluster.py :709 | node2: nodetool cmd=info wait=True timeout=60 17:17:43,282 ccm DEBUG cluster.py :709 | node3: nodetool cmd=info wait=True timeout=60 17:17:44,219 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1082 | Create entity_by_unique_id materialized view 17:17:44,223 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:44,223 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:44,227 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TABLE', 'change_type': 'CREATED', 'keyspace': 'abcinfo', 'table': 'entity_by_unique_id'} 17:17:44,227 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:44,227 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:44,431 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:44,636 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:44,840 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:45,044 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:45,248 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:45,255 tools.tables_view_manager DEBUG tables_view_manager.py:682 | Waiting for view abcinfo.entity_by_unique_id to finish building: num_nodes=3 num_alive=3 cl=QUORUM 17:17:45,259 tools.tables_view_manager DEBUG tables_view_manager.py:693 | wait_for_view abcinfo.entity_by_unique_id: status=defaultdict(, {'SUCCESS': {UUID('836cf1c5-7620-4c1b-a003-1e26c0378c95'), UUID('0816e4d5-7157-4010-9868-b971be0f1b70'), UUID('86d4a01a-a6ed-4aa0-954d-3e325c89b739')}}) 17:17:45,259 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1088 | Create entity_rel table 17:17:45,274 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:45,281 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TABLE', 'change_type': 'CREATED', 'keyspace': 'abcinfo', 'table': 'entity_rel'} 17:17:45,281 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:45,282 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:45,485 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:45,689 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:45,894 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:46,098 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:46,302 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:46,303 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:46,311 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:46,311 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1095 | Create index on entity_rel(dest_entity_id) 17:17:46,316 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:46,316 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:46,515 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:46,719 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:46,923 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:47,127 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:47,331 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:47,534 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:47,535 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:47,543 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:47,543 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:47,544 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TABLE', 'change_type': 'UPDATED', 'keyspace': 'abcinfo', 'table': 'entity_rel'} 17:17:47,545 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:47,545 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:47,546 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:47,548 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1099 | Create index on entity_rel(service) 17:17:47,552 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:47,553 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:47,553 cassandra.cluster DEBUG libevreactor.py:370 | Ignoring schedule_unique for already-scheduled task: (>, (), (('target_type', 'TABLE'), ('change_type', 'UPDATED'), ('keyspace', 'abcinfo'), ('table', 'entity_rel'))) 17:17:47,557 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TABLE', 'change_type': 'UPDATED', 'keyspace': 'abcinfo', 'table': 'entity_rel'} 17:17:47,557 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:47,557 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:47,761 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:47,966 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:48,170 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:48,171 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:48,181 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:48,182 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1102 | Create index on entity_rel(rel_type) 17:17:48,182 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:48,190 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:48,191 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:48,195 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:48,195 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:48,196 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:48,199 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TABLE', 'change_type': 'UPDATED', 'keyspace': 'abcinfo', 'table': 'entity_rel'} 17:17:48,199 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:48,200 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:48,404 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:48,609 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:48,814 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:49,018 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:49,223 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:49,231 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1130 | Start insert into entity 17:17:49,232 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1134 | Start insert into entity_rel 17:17:50,181 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1148 | Create priority_refs type 17:17:50,185 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:50,187 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TYPE', 'change_type': 'CREATED', 'keyspace': 'abcinfo', 'type': 'priority_refs'} 17:17:50,188 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:50,188 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:50,393 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:50,597 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:50,801 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:51,005 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:51,210 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:51,211 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:51,213 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1152 | Alter obs_entity type 17:17:51,215 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:51,216 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:51,224 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:51,224 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:51,226 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:51,226 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:51,226 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:51,227 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:51,230 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TYPE', 'change_type': 'UPDATED', 'keyspace': 'abcinfo', 'type': 'obs_entity'} 17:17:51,230 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:51,231 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:51,432 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:51,637 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:51,841 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:52,046 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:52,250 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:52,251 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:52,254 /home/jancio/code/scylla-dtest/user_types_test.py INFO user_types_test.py:1156 | Alter user_refs type 17:17:52,255 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:52,256 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:52,262 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:52,262 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:52,265 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:52,265 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:52,267 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:52,268 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:52,268 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:52,268 cassandra.connection DEBUG libevreactor.py:370 | Message pushed from server: 17:17:52,268 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:52,269 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:52,273 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:52,273 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:52,274 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:52,478 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:52,683 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:52,887 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:53,092 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:53,294 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:53,495 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas mismatched, trying again 17:17:53,699 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:53,700 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:53,707 cassandra.cluster DEBUG thread.py :58 | Refreshing schema in response to schema change. {'target_type': 'TYPE', 'change_type': 'UPDATED', 'keyspace': 'abcinfo', 'type': 'user_refs'} 17:17:53,708 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:53,709 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:53,717 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:53,718 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:53,722 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:53,723 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:53,729 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:53,729 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:53,734 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:53,735 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:53,742 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:53,743 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:53,751 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match 17:17:53,752 cassandra.cluster DEBUG thread.py :58 | [control connection] Waiting for schema agreement 17:17:53,760 cassandra.cluster DEBUG thread.py :58 | [control connection] Schemas match ---------------------------- Captured log teardown ----------------------------- 17:17:54,015 cassandra.cluster DEBUG conftest.py :328 | Shutting down Cluster Scheduler 17:17:54,015 cassandra.cluster DEBUG conftest.py :328 | Shutting down control connection 17:17:54,015 cassandra.io.libevreactor DEBUG libevreactor.py:287 | Closing connection (139996771306640) to 127.0.89.1:9042 17:17:54,015 cassandra.io.libevreactor DEBUG libevreactor.py:291 | Closed socket to 127.0.89.1:9042 17:17:54,016 cassandra.pool DEBUG conftest.py :328 | Shutting down connections to 127.0.89.1:9042 17:17:54,016 cassandra.pool DEBUG conftest.py :328 | Closing connection (139996779874256) to 127.0.89.1:9042 17:17:54,016 cassandra.io.libevreactor DEBUG libevreactor.py:287 | Closing connection (139996779874256) to 127.0.89.1:9042 17:17:54,016 cassandra.io.libevreactor DEBUG libevreactor.py:291 | Closed socket to 127.0.89.1:9042 17:17:54,016 cassandra.pool DEBUG conftest.py :328 | Closing connection (139996785990672) to 127.0.89.1:9042 17:17:54,016 cassandra.io.libevreactor DEBUG libevreactor.py:287 | Closing connection (139996785990672) to 127.0.89.1:19042 17:17:54,016 cassandra.io.libevreactor DEBUG libevreactor.py:291 | Closed socket to 127.0.89.1:19042 17:17:54,016 cassandra.pool DEBUG conftest.py :328 | Shutting down connections to 127.0.89.2:9042 17:17:54,016 cassandra.pool DEBUG conftest.py :328 | Closing connection (139996779873040) to 127.0.89.2:9042 17:17:54,016 cassandra.io.libevreactor DEBUG libevreactor.py:287 | Closing connection (139996779873040) to 127.0.89.2:9042 17:17:54,016 cassandra.io.libevreactor DEBUG libevreactor.py:291 | Closed socket to 127.0.89.2:9042 17:17:54,016 cassandra.pool DEBUG conftest.py :328 | Closing connection (139996782357136) to 127.0.89.2:9042 17:17:54,016 cassandra.io.libevreactor DEBUG libevreactor.py:287 | Closing connection (139996782357136) to 127.0.89.2:19042 17:17:54,016 cassandra.io.libevreactor DEBUG libevreactor.py:291 | Closed socket to 127.0.89.2:19042 17:17:54,016 cassandra.pool DEBUG conftest.py :328 | Shutting down connections to 127.0.89.3:9042 17:17:54,016 cassandra.pool DEBUG conftest.py :328 | Closing connection (139996785115088) to 127.0.89.3:9042 17:17:54,017 cassandra.io.libevreactor DEBUG libevreactor.py:287 | Closing connection (139996785115088) to 127.0.89.3:9042 17:17:54,017 cassandra.io.libevreactor DEBUG libevreactor.py:291 | Closed socket to 127.0.89.3:9042 17:17:54,017 cassandra.pool DEBUG conftest.py :328 | Closing connection (139996782348688) to 127.0.89.3:9042 17:17:54,017 cassandra.io.libevreactor DEBUG libevreactor.py:287 | Closing connection (139996782348688) to 127.0.89.3:19042 17:17:54,017 cassandra.io.libevreactor DEBUG libevreactor.py:291 | Closed socket to 127.0.89.3:19042 17:17:57,050 dtest_setup DEBUG dtest_setup.py :639 | removing ccm cluster test at: /home/jancio/.dtest/dtest-eqso2zue 17:17:57,092 dtest_setup DEBUG dtest_setup.py :643 | clearing ssl stores from [/home/jancio/.dtest/dtest-eqso2zue] directory 17:17:57,092 dtest_setup DEBUG dtest_setup.py :85 | Freeing cluster ID 89: link /home/jancio/.dtest/89