CI Summary

Failed: Timeout >900.0s-self = 

    @since('3.10')
    def test_disk_balance_after_boundary_change_lcs(self):
        """
        @jira_ticket CASSANDRA-13948
        """
>       self._disk_balance_after_boundary_change_test(lcs=True)

disk_balance_test.py:201: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
disk_balance_test.py:264: in _disk_balance_after_boundary_change_test
    self._assert_balanced_after_boundary_change(node2, total_keys, lcs)
disk_balance_test.py:353: in _assert_balanced_after_boundary_change
    node.stress(['read', 'n={}'.format(total_keys), "no-warmup", "cl=ALL", "-pop", "seq=1...{}".format(total_keys), "-rate", "threads=1"])
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:1529: in stress
    return handle_external_tool_process(p, ['stress'] + stress_options)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:2325: in handle_external_tool_process
    out, err = process.communicate()
/usr/lib/python3.8/subprocess.py:1028: in communicate
    stdout, stderr = self._communicate(input, endtime, timeout)
/usr/lib/python3.8/subprocess.py:1868: in _communicate
    ready = selector.select(timeout)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = , timeout = None

    def select(self, timeout=None):
        # This is shared between poll() and epoll().
        # epoll() has a different signature and handling of timeout parameter.
        if timeout is None:
            timeout = None
        elif timeout <= 0:
            timeout = 0
        else:
            # poll() has a resolution of 1 millisecond, round away from
            # zero to wait *at least* timeout seconds.
            timeout = math.ceil(timeout * 1e3)
        ready = []
        try:
>           fd_event_list = self._selector.poll(timeout)
E           Failed: Timeout >900.0s

/usr/lib/python3.8/selectors.py:415: Failed

cassandra.WriteTimeout: Error from server: code=1100 [Coordinator node timed out waiting for replica nodes' responses] message="Operation timed out - received 0/1 responses." info={'consistency': 'ONE', 'required_responses': 1, 'received_responses': 0, 'write_type': 'COUNTER'}-self = 

    def test_counter_node_down(self):
        """
        @jira_ticket CASSANDRA-17411
        """
        cluster = self.cluster
        cluster.populate(3).start()
        node1, node2, node3 = cluster.nodelist()
        session = self.patient_cql_connection(node1)
        create_ks(session, 'counter_tests', 3)
    
        session.execute("""
            CREATE TABLE IF NOT EXISTS counter_cs (
                key text PRIMARY KEY,
                count counter
            )
            """)
    
        node2.stop(gently=False, wait_other_notice=True)
    
        for _ in range(0, 20):
>           session.execute("UPDATE counter_cs SET count = count + 1 WHERE key = 'test'")

counter_test.py:447: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
../cassandra/build/venv/src/cassandra-driver/cassandra/cluster.py:2618: in execute
    return self.execute_async(query, parameters, trace, custom_payload, timeout, execution_profile, paging_state, host, execute_as).result()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = 

    def result(self):
        """
        Return the final result or raise an Exception if errors were
        encountered.  If the final result or error has not been set
        yet, this method will block until it is set, or the timeout
        set for the request expires.
    
        Timeout is specified in the Session request execution functions.
        If the timeout is exceeded, an :exc:`cassandra.OperationTimedOut` will be raised.
        This is a client-side timeout. For more information
        about server-side coordinator timeouts, see :class:`.policies.RetryPolicy`.
    
        Example usage::
    
            >>> future = session.execute_async("SELECT * FROM mycf")
            >>> # do other stuff...
    
            >>> try:
            ...     rows = future.result()
            ...     for row in rows:
            ...         ... # process results
            ... except Exception:
            ...     log.exception("Operation failed:")
    
        """
        self._event.wait()
        if self._final_result is not _NOT_SET:
            return ResultSet(self, self._final_result)
        else:
>           raise self._final_exception
E           cassandra.WriteTimeout: Error from server: code=1100 [Coordinator node timed out waiting for replica nodes' responses] message="Operation timed out - received 0/1 responses." info={'consistency': 'ONE', 'required_responses': 1, 'received_responses': 0, 'write_type': 'COUNTER'}

../cassandra/build/venv/src/cassandra-driver/cassandra/cluster.py:4894: WriteTimeout

ccmlib.node.TimeoutError: timed out and did not find log entry: This node was decommissioned and will not rejoin the ring-self = 

    @since('3.0')
    def test_decommissioned_node_cant_rejoin(self):
        """
        @jira_ticket CASSANDRA-8801
    
        Test that a decommissioned node can't rejoin the cluster by:
    
        - creating a cluster,
        - decommissioning a node, and
        - asserting that the "decommissioned node won't rejoin" error is in the
        logs for that node and
        - asserting that the node is not running.
        """
        rejoin_err = 'This node was decommissioned and will not rejoin the ring'
        self.fixture_dtest_setup.ignore_log_patterns = list(self.fixture_dtest_setup.ignore_log_patterns) + [
            rejoin_err]
    
        self.cluster.populate(3).start()
        node1, node2, node3 = self.cluster.nodelist()
    
        logger.debug('decommissioning...')
        node3.decommission(force=self.cluster.version() >= '4.0')
        logger.debug('stopping...')
        node3.stop()
        logger.debug('attempting restart...')
        node3.start(wait_other_notice=False)
        timedout = False
        try:
            # usually takes 3 seconds, so give it a generous 15
            node3.watch_log_for(rejoin_err, timeout=15)
        except TimeoutError:
            # TimeoutError is not very helpful to the reader of the test output;
            # let that pass and move on to string assertion below
            timedout = True
    
        n3errors = node3.grep_log_for_errors()
        if len(n3errors) == 0 and timedout:
>           raise TimeoutError("timed out and did not find log entry: " + rejoin_err)
E           ccmlib.node.TimeoutError: timed out and did not find log entry: This node was decommissioned and will not rejoin the ring

topology_test.py:425: TimeoutError

ccmlib.node.TimeoutError: 27 Nov 2024 09:35:21 [node3] after 20.04/20 seconds Missing: ['Replacing a node without bootstrapping risks invalidating consistency guarantees'] not found in system.log:
 Head: INFO  [main] 2024-11-27 09:35:07,028 YamlConfigura
 Tail: ...milliseconds
INFO  [main] 2024-11-27 09:35:16,576 MonotonicClock.java:351 - Scheduling approximate time-check task with a precision of 2 milliseconds-self = 

    @since('3.0')
    def test_fail_when_seed(self):
        """
        When a node is a seed replace should fail
        @jira_ticket CASSANDRA-14463
        """
        self.fixture_dtest_setup.ignore_log_patterns = list(self.fixture_dtest_setup.ignore_log_patterns) + [
            r'Couldn\'t find table with id 5bc52802-de25-35ed-aeab-188eecebb090', # system_auth
            r'Exception encountered during startup',
            r'Unknown endpoint'
        ]
    
        # see CASSANDRA-17611
        if self.cluster.version() < '4.0':
            self.fixture_dtest_setup.ignore_log_patterns = list(self.fixture_dtest_setup.ignore_log_patterns) + [
                r'RejectedExecutionException']
    
        self._setup(n=3)
        node1, node2, node3 = self.cluster.nodelist()
        self.cluster.seeds.append(node3.address())
    
        node3.stop(gently=False)
        mark = node3.mark_log()
    
        for d in chain([os.path.join(node3.get_path(), "commitlogs")],
                       [os.path.join(node3.get_path(), "saved_caches")],
                       node3.data_directories()):
            if os.path.exists(d):
                rmtree(d)
    
        node3.start(jvm_args=["-Dcassandra.replace_address=" + node3.address()], wait_other_notice=False)
>       node3.watch_log_for('Replacing a node without bootstrapping risks invalidating consistency guarantees', from_mark=mark, timeout=20)

replace_address_test.py:432: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:610: in watch_log_for
    TimeoutError.raise_if_passed(start=start, timeout=timeout, node=self.name,
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

start = 1732700101.5288508, timeout = 20
msg = "Missing: ['Replacing a node without bootstrapping risks invalidating consistency guarantees'] not found in system.log...-27 09:35:16,576 MonotonicClock.java:351 - Scheduling approximate time-check task with a precision of 2 milliseconds\n"
node = 'node3'

    @staticmethod
    def raise_if_passed(start, timeout, msg, node=None):
        if start + timeout < time.time():
>           raise TimeoutError.create(start, timeout, msg, node)
E           ccmlib.node.TimeoutError: 27 Nov 2024 09:35:21 [node3] after 20.04/20 seconds Missing: ['Replacing a node without bootstrapping risks invalidating consistency guarantees'] not found in system.log:
E            Head: INFO  [main] 2024-11-27 09:35:07,028 YamlConfigura
E            Tail: ...milliseconds
E           INFO  [main] 2024-11-27 09:35:16,576 MonotonicClock.java:351 - Scheduling approximate time-check task with a precision of 2 milliseconds

../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:56: TimeoutError

cassandra.OperationTimedOut: errors={'127.0.0.1:9042': 'Client request timeout. See Session.execute[_async](timeout)'}, last_host=127.0.0.1:9042-self = 

    def test_round_trip_with_rate_file(self):
        """
        Test a round trip with a large number of rows and a rate file. Make sure the rate file contains
        output statistics
    
        @jira_ticket CASSANDRA-9303
        """
        num_rows = 200000
        report_frequency = 0.1  # every 100 milliseconds
        stress_table = 'keyspace1.standard1'
        ratefile = self.get_temp_file()
        tempfile = self.get_temp_file()
    
        def check_rate_file():
            lines = [line.rstrip('\n') for line in open(ratefile.name)]
            logger.debug(lines)
            assert lines[-1].startswith('Processed: {} rows;'.format(num_rows))
    
        self.prepare()
    
        logger.debug('Running stress')
        self.node1.stress(['write', 'n={}'.format(num_rows), 'no-warmup', '-rate', 'threads=50'])
    
        logger.debug('Exporting to csv file: {}'.format(tempfile.name))
        self.run_cqlsh(cmds="COPY {} TO '{}' WITH RATEFILE='{}' AND REPORTFREQUENCY='{}'"
                       .format(stress_table, tempfile.name, ratefile.name, report_frequency))
    
        # check all records were exported
        assert num_rows == len(open(tempfile.name).readlines())
    
        check_rate_file()
    
        # clean-up
        os.unlink(ratefile.name)
        self.session.execute("TRUNCATE {}".format(stress_table))
    
        logger.debug('Importing from csv file: {}'.format(tempfile.name))
        self.run_cqlsh(cmds="COPY {} FROM '{}' WITH RATEFILE='{}' AND REPORTFREQUENCY='{}'"
                       .format(stress_table, tempfile.name, ratefile.name, report_frequency))
    
        # check all records were imported
>       assert [[num_rows]] == rows_to_list(self.session.execute("SELECT COUNT(*) FROM {}"
                                                                         .format(stress_table)))

cqlsh_tests/test_cqlsh_copy.py:2136: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
../cassandra/build/venv/src/cassandra-driver/cassandra/cluster.py:2618: in execute
    return self.execute_async(query, parameters, trace, custom_payload, timeout, execution_profile, paging_state, host, execute_as).result()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = 

    def result(self):
        """
        Return the final result or raise an Exception if errors were
        encountered.  If the final result or error has not been set
        yet, this method will block until it is set, or the timeout
        set for the request expires.
    
        Timeout is specified in the Session request execution functions.
        If the timeout is exceeded, an :exc:`cassandra.OperationTimedOut` will be raised.
        This is a client-side timeout. For more information
        about server-side coordinator timeouts, see :class:`.policies.RetryPolicy`.
    
        Example usage::
    
            >>> future = session.execute_async("SELECT * FROM mycf")
            >>> # do other stuff...
    
            >>> try:
            ...     rows = future.result()
            ...     for row in rows:
            ...         ... # process results
            ... except Exception:
            ...     log.exception("Operation failed:")
    
        """
        self._event.wait()
        if self._final_result is not _NOT_SET:
            return ResultSet(self, self._final_result)
        else:
>           raise self._final_exception
E           cassandra.OperationTimedOut: errors={'127.0.0.1:9042': 'Client request timeout. See Session.execute[_async](timeout)'}, last_host=127.0.0.1:9042

../cassandra/build/venv/src/cassandra-driver/cassandra/cluster.py:4894: OperationTimedOut

AssertionError: It's been over 180s and we haven't written a new commitlog segment. Something is wrong.-self = 

    def test_dont_archive_commitlog(self):
        """
        Run the archive commitlog test, but forget to add the restore commands
        """
>       self.run_archive_commitlog(restore_point_in_time=False, restore_archived_commitlog=False)

snapshot_test.py:255: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
snapshot_test.py:303: in run_archive_commitlog
    advance_to_next_cl_segment(
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

session = 
commitlog_dir = '/home/cassandra/cassandra/build/run-python-dtest.T3wZLX/dtest-tael4ce2/test/node1/commitlogs'
keyspace_name = 'ks', table_name = 'junk_table', timeout = 180

    def advance_to_next_cl_segment(session, commitlog_dir,
                                   keyspace_name='ks', table_name='junk_table',
                                   timeout=180):
        """
        This is a hack to work around problems like CASSANDRA-11811.
    
        The problem happens in commitlog-replaying tests, like the snapshot and CDC
        tests. If we replay the first commitlog that's created, we wind up
        replaying some mutations that initialize system tables, so this function
        advances the node to the next CL by filling up the first one.
        """
        session.execute(
            'CREATE TABLE {ks}.{tab} ('
            'a uuid PRIMARY KEY, b uuid, c uuid, d uuid, '
            'e uuid, f uuid, g uuid, h uuid'
            ')'.format(ks=keyspace_name, tab=table_name)
        )
        prepared_insert = session.prepare(
            'INSERT INTO {ks}.{tab} '
            '(a, b, c, d, e, f, g, h) '
            'VALUES ('
            'uuid(), uuid(), uuid(), uuid(), '
            'uuid(), uuid(), uuid(), uuid()'
            ')'.format(ks=keyspace_name, tab=table_name)
        )
    
        # record segments that we want to advance past
        initial_cl_files = _files_in(commitlog_dir)
    
        start = time.time()
        stop_time = start + timeout
        rate_limited_debug_logger = get_rate_limited_function(logger.debug, 5)
        logger.debug('attempting to write until we start writing to new CL segments: {}'.format(initial_cl_files))
    
        while _files_in(commitlog_dir) <= initial_cl_files:
            elapsed = time.time() - start
            rate_limited_debug_logger('  commitlog-advancing load step has lasted {s:.2f}s'.format(s=elapsed))
>           assert (
                time.time() <= stop_time), ("It's been over {s}s and we haven't written a new " +
                                            "commitlog segment. Something is wrong.").format(s=timeout)
E           AssertionError: It's been over 180s and we haven't written a new commitlog segment. Something is wrong.

tools/hacks.py:59: AssertionError

ccmlib.node.TimeoutError: timed out and did not find log entry: This node was decommissioned and will not rejoin the ring-self = 

    @since('3.0')
    def test_decommissioned_node_cant_rejoin(self):
        """
        @jira_ticket CASSANDRA-8801
    
        Test that a decommissioned node can't rejoin the cluster by:
    
        - creating a cluster,
        - decommissioning a node, and
        - asserting that the "decommissioned node won't rejoin" error is in the
        logs for that node and
        - asserting that the node is not running.
        """
        rejoin_err = 'This node was decommissioned and will not rejoin the ring'
        self.fixture_dtest_setup.ignore_log_patterns = list(self.fixture_dtest_setup.ignore_log_patterns) + [
            rejoin_err]
    
        self.cluster.populate(3).start()
        node1, node2, node3 = self.cluster.nodelist()
    
        logger.debug('decommissioning...')
        node3.decommission(force=self.cluster.version() >= '4.0')
        logger.debug('stopping...')
        node3.stop()
        logger.debug('attempting restart...')
        node3.start(wait_other_notice=False)
        timedout = False
        try:
            # usually takes 3 seconds, so give it a generous 15
            node3.watch_log_for(rejoin_err, timeout=15)
        except TimeoutError:
            # TimeoutError is not very helpful to the reader of the test output;
            # let that pass and move on to string assertion below
            timedout = True
    
        n3errors = node3.grep_log_for_errors()
        if len(n3errors) == 0 and timedout:
>           raise TimeoutError("timed out and did not find log entry: " + rejoin_err)
E           ccmlib.node.TimeoutError: timed out and did not find log entry: This node was decommissioned and will not rejoin the ring

topology_test.py:425: TimeoutError

ccmlib.node.TimeoutError: 27 Nov 2024 10:21:38 [node1] after 90.12/90 seconds Missing: ['Starting listening for CQL clients'] not found in system.log:
 Head: INFO  [main] 2024-11-27 10:20:10,434 YamlConfigura
 Tail: ...table: /home/cassandra/cassandra/build/run-python-dtest.axp368/dtest-v96os4_o/test/node1/data0/system/local-7ad54392bcdd35a684174e047860b377/nb-9-big-self = 

    @pytest.mark.timeout(3000)
    def test_parallel_upgrade_with_internode_ssl(self):
        """
        Test upgrading cluster all at once (requires cluster downtime), with internode ssl.
        """
>       self.upgrade_scenario(internode_ssl=True)

upgrade_tests/upgrade_through_versions_test.py:402: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
upgrade_tests/upgrade_through_versions_test.py:493: in upgrade_scenario
    self.upgrade_to_version(version_meta, internode_ssl=internode_ssl)
upgrade_tests/upgrade_through_versions_test.py:581: in upgrade_to_version
    node.start(wait_other_notice=400, wait_for_binary_proto=True,
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:928: in start
    self.wait_for_binary_interface(from_mark=self.mark)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:711: in wait_for_binary_interface
    self.watch_log_for("Starting listening for CQL clients", **kwargs)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:610: in watch_log_for
    TimeoutError.raise_if_passed(start=start, timeout=timeout, node=self.name,
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

start = 1732702808.45915, timeout = 90
msg = "Missing: ['Starting listening for CQL clients'] not found in system.log:\n Head: INFO  [main] 2024-11-27 10:20:10,434...build/run-python-dtest.axp368/dtest-v96os4_o/test/node1/data0/system/local-7ad54392bcdd35a684174e047860b377/nb-9-big\n"
node = 'node1'

    @staticmethod
    def raise_if_passed(start, timeout, msg, node=None):
        if start + timeout < time.time():
>           raise TimeoutError.create(start, timeout, msg, node)
E           ccmlib.node.TimeoutError: 27 Nov 2024 10:21:38 [node1] after 90.12/90 seconds Missing: ['Starting listening for CQL clients'] not found in system.log:
E            Head: INFO  [main] 2024-11-27 10:20:10,434 YamlConfigura
E            Tail: ...table: /home/cassandra/cassandra/build/run-python-dtest.axp368/dtest-v96os4_o/test/node1/data0/system/local-7ad54392bcdd35a684174e047860b377/nb-9-big

../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:56: TimeoutError

ccmlib.node.TimeoutError: 27 Nov 2024 10:39:45 [node1] after 90.19/90 seconds Missing: ['Starting listening for CQL clients'] not found in system.log:
 Head: INFO  [main] 2024-11-27 10:38:20,517 YamlConfigura
 Tail: ...system/local-7ad54392bcdd35a684174e047860b377/oa-16-big-Data.db (39B) for commitlog position CommitLogPosition(segmentId=1732703911428, position=284)-self = 

    @pytest.mark.timeout(3000)
    def test_parallel_upgrade(self):
        """
        Test upgrading cluster all at once (requires cluster downtime).
        """
>       self.upgrade_scenario()

upgrade_tests/upgrade_through_versions_test.py:388: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
upgrade_tests/upgrade_through_versions_test.py:493: in upgrade_scenario
    self.upgrade_to_version(version_meta, internode_ssl=internode_ssl)
upgrade_tests/upgrade_through_versions_test.py:581: in upgrade_to_version
    node.start(wait_other_notice=400, wait_for_binary_proto=True,
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:928: in start
    self.wait_for_binary_interface(from_mark=self.mark)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:711: in wait_for_binary_interface
    self.watch_log_for("Starting listening for CQL clients", **kwargs)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:610: in watch_log_for
    TimeoutError.raise_if_passed(start=start, timeout=timeout, node=self.name,
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

start = 1732703895.1092641, timeout = 90
msg = "Missing: ['Starting listening for CQL clients'] not found in system.log:\n Head: INFO  [main] 2024-11-27 10:38:20,517...4e047860b377/oa-16-big-Data.db (39B) for commitlog position CommitLogPosition(segmentId=1732703911428, position=284)\n"
node = 'node1'

    @staticmethod
    def raise_if_passed(start, timeout, msg, node=None):
        if start + timeout < time.time():
>           raise TimeoutError.create(start, timeout, msg, node)
E           ccmlib.node.TimeoutError: 27 Nov 2024 10:39:45 [node1] after 90.19/90 seconds Missing: ['Starting listening for CQL clients'] not found in system.log:
E            Head: INFO  [main] 2024-11-27 10:38:20,517 YamlConfigura
E            Tail: ...system/local-7ad54392bcdd35a684174e047860b377/oa-16-big-Data.db (39B) for commitlog position CommitLogPosition(segmentId=1732703911428, position=284)

../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:56: TimeoutError

ccmlib.node.TimeoutError: 27 Nov 2024 11:03:42 [node1] after 90.17/90 seconds Missing: ['Starting listening for CQL clients'] not found in system.log:
 Head: INFO  [main] 2024-11-27 11:02:17,367 YamlConfigura
 Tail: .....
WARN  [GossipTasks:1] 2024-11-27 11:03:37,055 FailureDetector.java:355 - Not marking nodes down due to local pause of 68222755356ns > 5000000000ns-self = 

    @pytest.mark.timeout(3000)
    def test_parallel_upgrade_with_internode_ssl(self):
        """
        Test upgrading cluster all at once (requires cluster downtime), with internode ssl.
        """
>       self.upgrade_scenario(internode_ssl=True)

upgrade_tests/upgrade_through_versions_test.py:402: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
upgrade_tests/upgrade_through_versions_test.py:493: in upgrade_scenario
    self.upgrade_to_version(version_meta, internode_ssl=internode_ssl)
upgrade_tests/upgrade_through_versions_test.py:581: in upgrade_to_version
    node.start(wait_other_notice=400, wait_for_binary_proto=True,
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:928: in start
    self.wait_for_binary_interface(from_mark=self.mark)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:711: in wait_for_binary_interface
    self.watch_log_for("Starting listening for CQL clients", **kwargs)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:610: in watch_log_for
    TimeoutError.raise_if_passed(start=start, timeout=timeout, node=self.name,
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

start = 1732705332.6813624, timeout = 90
msg = "Missing: ['Starting listening for CQL clients'] not found in system.log:\n Head: INFO  [main] 2024-11-27 11:02:17,367...27 11:03:37,055 FailureDetector.java:355 - Not marking nodes down due to local pause of 68222755356ns > 5000000000ns\n"
node = 'node1'

    @staticmethod
    def raise_if_passed(start, timeout, msg, node=None):
        if start + timeout < time.time():
>           raise TimeoutError.create(start, timeout, msg, node)
E           ccmlib.node.TimeoutError: 27 Nov 2024 11:03:42 [node1] after 90.17/90 seconds Missing: ['Starting listening for CQL clients'] not found in system.log:
E            Head: INFO  [main] 2024-11-27 11:02:17,367 YamlConfigura
E            Tail: .....
E           WARN  [GossipTasks:1] 2024-11-27 11:03:37,055 FailureDetector.java:355 - Not marking nodes down due to local pause of 68222755356ns > 5000000000ns

../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:56: TimeoutError

ccmlib.node.TimeoutError: 27 Nov 2024 02:00:47 [node1] after 90.16/90 seconds Missing: ['Starting listening for CQL clients'] not found in system.log:
 Head: INFO  [main] 2024-11-27 01:59:21,699 YamlConfigura
 Tail: .....
WARN  [GossipTasks:1] 2024-11-27 02:00:40,527 FailureDetector.java:355 - Not marking nodes down due to local pause of 68028592711ns > 5000000000ns-self = 

    def test_bootstrap(self):
        # try and add a new node
>       self.upgrade_scenario(after_upgrade_call=(self._bootstrap_new_node,))

upgrade_tests/upgrade_through_versions_test.py:845: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
upgrade_tests/upgrade_through_versions_test.py:493: in upgrade_scenario
    self.upgrade_to_version(version_meta, internode_ssl=internode_ssl)
upgrade_tests/upgrade_through_versions_test.py:581: in upgrade_to_version
    node.start(wait_other_notice=400, wait_for_binary_proto=True,
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:928: in start
    self.wait_for_binary_interface(from_mark=self.mark)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:711: in wait_for_binary_interface
    self.watch_log_for("Starting listening for CQL clients", **kwargs)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:610: in watch_log_for
    TimeoutError.raise_if_passed(start=start, timeout=timeout, node=self.name,
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

start = 1732672757.4928458, timeout = 90
msg = "Missing: ['Starting listening for CQL clients'] not found in system.log:\n Head: INFO  [main] 2024-11-27 01:59:21,699...27 02:00:40,527 FailureDetector.java:355 - Not marking nodes down due to local pause of 68028592711ns > 5000000000ns\n"
node = 'node1'

    @staticmethod
    def raise_if_passed(start, timeout, msg, node=None):
        if start + timeout < time.time():
>           raise TimeoutError.create(start, timeout, msg, node)
E           ccmlib.node.TimeoutError: 27 Nov 2024 02:00:47 [node1] after 90.16/90 seconds Missing: ['Starting listening for CQL clients'] not found in system.log:
E            Head: INFO  [main] 2024-11-27 01:59:21,699 YamlConfigura
E            Tail: .....
E           WARN  [GossipTasks:1] 2024-11-27 02:00:40,527 FailureDetector.java:355 - Not marking nodes down due to local pause of 68028592711ns > 5000000000ns

../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:56: TimeoutError

ccmlib.common.UnavailableSocketError: Inet address 127.0.0.2:7000 is not available: [Errno 98] Address already in use; a cluster may already be running or you may need to add the loopback alias-itf = ('127.0.0.2', 7000)

    def assert_socket_available(itf):
        info = socket.getaddrinfo(itf[0], itf[1], socket.AF_UNSPEC, socket.SOCK_STREAM)
        if not info:
            raise UnavailableSocketError("Failed to get address info for [%s]:%s" % itf)
    
        (family, socktype, proto, canonname, sockaddr) = info[0]
        s = socket.socket(family, socktype)
        s.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
    
        try:
>           s.bind(sockaddr)
E           OSError: [Errno 98] Address already in use

../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/common.py:631: OSError

During handling of the above exception, another exception occurred:

self = 

    def test_correct_dc_rack_in_nodetool_info(self):
        """
        @jira_ticket CASSANDRA-10382
    
        Test that nodetool info returns the correct rack and dc
        """
    
        cluster = self.cluster
        cluster.populate([2, 2])
        cluster.set_configuration_options(values={'endpoint_snitch': 'org.apache.cassandra.locator.GossipingPropertyFileSnitch'})
    
        for i, node in enumerate(cluster.nodelist()):
            with open(os.path.join(node.get_conf_dir(), 'cassandra-rackdc.properties'), 'w') as snitch_file:
                for line in ["dc={}".format(node.data_center), "rack=rack{}".format(i % 2)]:
                    snitch_file.write(line + os.linesep)
    
>       cluster.start()

nodetool_test.py:59: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/cluster.py:515: in start
    common.assert_socket_available(itf)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

itf = ('127.0.0.2', 7000)

    def assert_socket_available(itf):
        info = socket.getaddrinfo(itf[0], itf[1], socket.AF_UNSPEC, socket.SOCK_STREAM)
        if not info:
            raise UnavailableSocketError("Failed to get address info for [%s]:%s" % itf)
    
        (family, socktype, proto, canonname, sockaddr) = info[0]
        s = socket.socket(family, socktype)
        s.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
    
        try:
            s.bind(sockaddr)
            s.close()
            return True
        except socket.error as msg:
            s.close()
            addr, port = itf
>           raise UnavailableSocketError(
                "Inet address %s:%s is not available: %s; a cluster may already be running or you may need to add the loopback alias" % (
                addr, port, msg))
E           ccmlib.common.UnavailableSocketError: Inet address 127.0.0.2:7000 is not available: [Errno 98] Address already in use; a cluster may already be running or you may need to add the loopback alias

../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/common.py:637: UnavailableSocketError

ccmlib.common.UnavailableSocketError: Inet address 127.0.0.2:7000 is not available: [Errno 98] Address already in use; a cluster may already be running or you may need to add the loopback alias-itf = ('127.0.0.2', 7000)

    def assert_socket_available(itf):
        info = socket.getaddrinfo(itf[0], itf[1], socket.AF_UNSPEC, socket.SOCK_STREAM)
        if not info:
            raise UnavailableSocketError("Failed to get address info for [%s]:%s" % itf)
    
        (family, socktype, proto, canonname, sockaddr) = info[0]
        s = socket.socket(family, socktype)
        s.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
    
        try:
>           s.bind(sockaddr)
E           OSError: [Errno 98] Address already in use

../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/common.py:631: OSError

During handling of the above exception, another exception occurred:

self = 

    def test_cell_TTL_expiry_during_paging(self):
>       session = self.prepare()

paging_test.py:2950: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
paging_test.py:33: in prepare
    cluster.populate(3).start()
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/cluster.py:515: in start
    common.assert_socket_available(itf)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

itf = ('127.0.0.2', 7000)

    def assert_socket_available(itf):
        info = socket.getaddrinfo(itf[0], itf[1], socket.AF_UNSPEC, socket.SOCK_STREAM)
        if not info:
            raise UnavailableSocketError("Failed to get address info for [%s]:%s" % itf)
    
        (family, socktype, proto, canonname, sockaddr) = info[0]
        s = socket.socket(family, socktype)
        s.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
    
        try:
            s.bind(sockaddr)
            s.close()
            return True
        except socket.error as msg:
            s.close()
            addr, port = itf
>           raise UnavailableSocketError(
                "Inet address %s:%s is not available: %s; a cluster may already be running or you may need to add the loopback alias" % (
                addr, port, msg))
E           ccmlib.common.UnavailableSocketError: Inet address 127.0.0.2:7000 is not available: [Errno 98] Address already in use; a cluster may already be running or you may need to add the loopback alias

../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/common.py:637: UnavailableSocketError

cassandra.cluster.NoHostAvailable: ('Unable to connect to any servers', {'127.0.0.1:9042': ConnectionRefusedError(111, "Tried connecting to [('127.0.0.1', 9042)]. Last error: Connection refused")})-self = 

    @since('3.0.7')
    def test_mv_lock_contention_during_replay(self):
        """
        Ensure that we don't generate WriteTimeoutExceptions during commitlog
        replay due to MV lock contention.  Fixed in 3.0.7 and 3.7.
        @jira_ticket CASSANDRA-11891
        """
        cluster_ver = self.cluster.version()
        if LooseVersion('3.1') <= cluster_ver < LooseVersion('3.7'):
            pytest.skip("Fixed in 3.0.7 and 3.7")
    
        node1 = self.node1
        node1.set_batch_commitlog(enabled=True, use_batch_window = self.cluster.version() < '5.0')
        node1.start()
>       session = self.patient_cql_connection(node1)

commitlog_test.py:181: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
dtest_setup.py:284: in patient_cql_connection
    session = retry_till_success(
dtest_setup.py:39: in retry_till_success
    return fun(*args, **kwargs)
dtest_setup.py:222: in cql_connection
    return self._create_session(node, keyspace, user, password, compression,
dtest_setup.py:262: in _create_session
    session = cluster.connect(wait_for_all_pools=True)
../cassandra/build/venv/src/cassandra-driver/cassandra/cluster.py:1690: in connect
    self.control_connection.connect()
../cassandra/build/venv/src/cassandra-driver/cassandra/cluster.py:3488: in connect
    self._set_new_connection(self._reconnect_internal())
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = 

    def _reconnect_internal(self):
        """
        Tries to connect to each host in the query plan until one succeeds
        or every attempt fails. If successful, a new Connection will be
        returned.  Otherwise, :exc:`NoHostAvailable` will be raised
        with an "errors" arg that is a dict mapping host addresses
        to the exception that was raised when an attempt was made to open
        a connection to that host.
        """
        errors = {}
        lbp = (
            self._cluster.load_balancing_policy
            if self._cluster._config_mode == _ConfigMode.LEGACY else
            self._cluster._default_load_balancing_policy
        )
    
        for host in lbp.make_query_plan():
            try:
                return self._try_connect(host)
            except ConnectionException as exc:
                errors[str(host.endpoint)] = exc
                log.warning("[control connection] Error connecting to %s:", host, exc_info=True)
                self._cluster.signal_connection_failure(host, exc, is_host_addition=False)
            except Exception as exc:
                errors[str(host.endpoint)] = exc
                log.warning("[control connection] Error connecting to %s:", host, exc_info=True)
            if self._is_shutdown:
                raise DriverException("[control connection] Reconnection in progress during shutdown")
    
>       raise NoHostAvailable("Unable to connect to any servers", errors)
E       cassandra.cluster.NoHostAvailable: ('Unable to connect to any servers', {'127.0.0.1:9042': ConnectionRefusedError(111, "Tried connecting to [('127.0.0.1', 9042)]. Last error: Connection refused")})

../cassandra/build/venv/src/cassandra-driver/cassandra/cluster.py:3533: NoHostAvailable

ccmlib.node.TimeoutError: 27 Nov 2024 14:23:28 [node1] after 120.16/120 seconds Missing: ['127.0.0.2:7000.* is now UP'] not found in system.log:
 Head: INFO  [GossipStage:1] 2024-11-27 14:21:29,858 Goss
 Tail: ....0.0.1:7000(/127.0.0.1:41336)->/127.0.0.2:7000-URGENT_MESSAGES-faa40d29 successfully connected, version = 14, framing = CRC, encryption = unencrypted-self = 

    def test_disk_balance_replace_same_address(self):
>       self._test_disk_balance_replace(same_address=True)

disk_balance_test.py:69: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
disk_balance_test.py:100: in _test_disk_balance_replace
    node5.start(jvm_args=["-Dcassandra.replace_address_first_boot={}".format(node2.address())],
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:922: in start
    node.watch_log_for_alive(self, from_mark=mark)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:686: in watch_log_for_alive
    self.watch_log_for(tofind, from_mark=from_mark, timeout=timeout, filename=filename)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:610: in watch_log_for
    TimeoutError.raise_if_passed(start=start, timeout=timeout, node=self.name,
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

start = 1732717287.921752, timeout = 120
msg = "Missing: ['127.0.0.2:7000.* is now UP'] not found in system.log:\n Head: INFO  [GossipStage:1] 2024-11-27 14:21:29,85...27.0.0.2:7000-URGENT_MESSAGES-faa40d29 successfully connected, version = 14, framing = CRC, encryption = unencrypted\n"
node = 'node1'

    @staticmethod
    def raise_if_passed(start, timeout, msg, node=None):
        if start + timeout < time.time():
>           raise TimeoutError.create(start, timeout, msg, node)
E           ccmlib.node.TimeoutError: 27 Nov 2024 14:23:28 [node1] after 120.16/120 seconds Missing: ['127.0.0.2:7000.* is now UP'] not found in system.log:
E            Head: INFO  [GossipStage:1] 2024-11-27 14:21:29,858 Goss
E            Tail: ....0.0.1:7000(/127.0.0.1:41336)->/127.0.0.2:7000-URGENT_MESSAGES-faa40d29 successfully connected, version = 14, framing = CRC, encryption = unencrypted

../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:56: TimeoutError

Failed: Timeout >900.0s-self = 

    @since('3.10')
    def test_disk_balance_after_joining_ring_stcs(self):
        """
        @jira_ticket CASSANDRA-13948
        """
>       self._disk_balance_after_joining_ring_test(lcs=False)

disk_balance_test.py:271: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
disk_balance_test.py:331: in _disk_balance_after_joining_ring_test
    self._assert_balanced_after_boundary_change(node1, total_keys, lcs)
disk_balance_test.py:353: in _assert_balanced_after_boundary_change
    node.stress(['read', 'n={}'.format(total_keys), "no-warmup", "cl=ALL", "-pop", "seq=1...{}".format(total_keys), "-rate", "threads=1"])
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:1529: in stress
    return handle_external_tool_process(p, ['stress'] + stress_options)
../cassandra/build/venv/lib/python3.8/site-packages/ccmlib/node.py:2325: in handle_external_tool_process
    out, err = process.communicate()
/usr/lib/python3.8/subprocess.py:1028: in communicate
    stdout, stderr = self._communicate(input, endtime, timeout)
/usr/lib/python3.8/subprocess.py:1868: in _communicate
    ready = selector.select(timeout)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = , timeout = None

    def select(self, timeout=None):
        # This is shared between poll() and epoll().
        # epoll() has a different signature and handling of timeout parameter.
        if timeout is None:
            timeout = None
        elif timeout <= 0:
            timeout = 0
        else:
            # poll() has a resolution of 1 millisecond, round away from
            # zero to wait *at least* timeout seconds.
            timeout = math.ceil(timeout * 1e3)
        ready = []
        try:
>           fd_event_list = self._selector.poll(timeout)
E           Failed: Timeout >900.0s

/usr/lib/python3.8/selectors.py:415: Failed

Timeout occurred. Please note the time in the report does not reflect the time until the timeout.-junit.framework.AssertionFailedError: Timeout occurred. Please note the time in the report does not reflect the time until the timeout.
	at jdk.internal.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.util.Vector.forEach(Vector.java:1394)
	at jdk.internal.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at jdk.internal.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.util.Vector.forEach(Vector.java:1394)
	at jdk.internal.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at jdk.internal.reflect.GeneratedMethodAccessor47.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.util.Vector.forEach(Vector.java:1394)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at org.apache.cassandra.anttasks.TestHelper.execute(TestHelper.java:53)
	at jdk.internal.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.util.Vector.forEach(Vector.java:1394)
	at jdk.internal.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at jdk.internal.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)