Details
-
Bug
-
Status: Resolved
-
Normal
-
Resolution: Fixed
-
Correctness - Test Failure
-
Normal
-
Normal
-
Unit Test
-
All
-
None
-
Description
Example failure: https://circleci.com/gh/vinaykumarchella/cassandra/468#tests/containers/11
ccmlib.node.TimeoutError: 06 Sep 2019 20:23:57 [node2] Missing: ['127.0.0.1.* now UP']: INFO [HANDSHAKE-/127.0.0.1] 2019-09-06 20:20:01,7..... See system.log for remainder self = <upgrade_tests.upgrade_through_versions_test.TestProtoV4Upgrade_AllVersions_EndsAt_Trunk_HEAD object at 0x7f6d90d43b38> @pytest.mark.timeout(3000) def test_rolling_upgrade_with_internode_ssl(self): """ Rolling upgrade test using internode ssl. """ > self.upgrade_scenario(rolling=True, internode_ssl=True) upgrade_tests/upgrade_through_versions_test.py:296: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ upgrade_tests/upgrade_through_versions_test.py:352: in upgrade_scenario self.upgrade_to_version(version_meta, partial=True, nodes=(node,), internode_ssl=internode_ssl) upgrade_tests/upgrade_through_versions_test.py:456: in upgrade_to_version node.start(wait_other_notice=240, wait_for_binary_proto=True) ../env/src/ccm/ccmlib/node.py:751: in start node.watch_log_for_alive(self, from_mark=mark, timeout=wait_other_notice) ../env/src/ccm/ccmlib/node.py:568: in watch_log_for_alive self.watch_log_for(tofind, from_mark=from_mark, timeout=timeout, filename=filename) _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = <ccmlib.node.Node object at 0x7f6d90e705f8> exprs = ['127.0.0.1.* now UP'], from_mark = 150742, timeout = 240 process = None, verbose = False, filename = 'system.log' def watch_log_for(self, exprs, from_mark=None, timeout=600, process=None, verbose=False, filename='system.log'): """ Watch the log until one or more (regular) expression are found. This methods when all the expressions have been found or the method timeouts (a TimeoutError is then raised). On successful completion, a list of pair (line matched, match object) is returned. """ start = time.time() tofind = [exprs] if isinstance(exprs, string_types) else exprs tofind = [re.compile(e) for e in tofind] matchings = [] reads = "" if len(tofind) == 0: return None log_file = os.path.join(self.get_path(), 'logs', filename) output_read = False while not os.path.exists(log_file): time.sleep(.5) if start + timeout < time.time(): raise TimeoutError(time.strftime("%d %b %Y %H:%M:%S", time.gmtime()) + " [" + self.name + "] Timed out waiting for {} to be created.".format(log_file)) if process and not output_read: process.poll() if process.returncode is not None: self.print_process_output(self.name, process, verbose) output_read = True if process.returncode != 0: raise RuntimeError() # Shouldn't reuse RuntimeError but I'm lazy with open(log_file) as f: if from_mark: f.seek(from_mark) while True: # First, if we have a process to check, then check it. # Skip on Windows - stdout/stderr is cassandra.bat if not common.is_win() and not output_read: if process: process.poll() if process.returncode is not None: self.print_process_output(self.name, process, verbose) output_read = True if process.returncode != 0: raise RuntimeError() # Shouldn't reuse RuntimeError but I'm lazy line = f.readline() if line: reads = reads + line for e in tofind: m = e.search(line) if m: matchings.append((line, m)) tofind.remove(e) if len(tofind) == 0: return matchings[0] if isinstance(exprs, string_types) else matchings else: # yep, it's ugly time.sleep(1) if start + timeout < time.time(): > raise TimeoutError(time.strftime("%d %b %Y %H:%M:%S", time.gmtime()) + " [" + self.name + "] Missing: " + str([e.pattern for e in tofind]) + ":\n" + reads[:50] + ".....\nSee {} for remainder".format(filename)) E ccmlib.node.TimeoutError: 06 Sep 2019 20:23:57 [node2] Missing: ['127.0.0.1.* now UP']: E INFO [HANDSHAKE-/127.0.0.1] 2019-09-06 20:20:01,7..... E See system.log for remainder ../env/src/ccm/ccmlib/node.py:536: TimeoutError