diff --git a/grizzly/common/report.py b/grizzly/common/report.py index 19cde52c..e2f6686a 100644 --- a/grizzly/common/report.py +++ b/grizzly/common/report.py @@ -52,6 +52,7 @@ class Report: "path", "prefix", "stack", + "unstable", ) def __init__( @@ -60,6 +61,7 @@ def __init__( target_binary: Path, is_hang: bool = False, size_limit: int = MAX_LOG_SIZE, + unstable: bool = False, ) -> None: self._crash_info: Optional[CrashInfo] = None self._logs = self._select_logs(log_path) @@ -69,6 +71,8 @@ def __init__( self._target_binary = target_binary self.is_hang = is_hang self.path = log_path + # if a build crashes before the initial testcase is served it is unstable + self.unstable = unstable # tail files in log_path if needed if size_limit < 1: LOG.warning("No limit set on report log size!") diff --git a/grizzly/common/reporter.py b/grizzly/common/reporter.py index 53ee02de..fc7b3a27 100644 --- a/grizzly/common/reporter.py +++ b/grizzly/common/reporter.py @@ -259,6 +259,9 @@ def _submit_report( if report.is_hang: self.add_extra_metadata("is_hang", True) + if report.unstable: + self.add_extra_metadata("unstable_build", True) + # dump test cases and the contained files to working directory test_case_meta = [] for test_number, test_case in enumerate(reversed(test_cases)): diff --git a/grizzly/common/runner.py b/grizzly/common/runner.py index e64659ee..0aa975e0 100644 --- a/grizzly/common/runner.py +++ b/grizzly/common/runner.py @@ -248,7 +248,7 @@ def initial(self) -> bool: """ return self._tests_run < 2 - def post_launch(self, delay: int = -1) -> None: + def post_launch(self, delay: int = 0) -> None: """Perform actions after launching browser before loading test cases. Args: @@ -257,41 +257,38 @@ def post_launch(self, delay: int = -1) -> None: Returns: None """ - if delay >= 0 and not self.startup_failure: - with TestCase("post_launch_delay.html", "None") as content: - content.add_from_file( - Path(__file__).parent / "post_launch_delay.html", - file_name=content.entry_point, - copy=True, - ) - srv_map = ServerMap() - srv_map.set_redirect("grz_start", content.entry_point, required=False) - srv_map.set_redirect("grz_continue", "grz_start", required=True) - # temporarily override server timeout - org_timeout = self._server.timeout - # add time buffer to redirect delay - # in practice this should take a few seconds (~10s) - # in extreme cases ~40s (slow build + debugger) - self._server.timeout = delay + 180 - if delay > 0: - LOG.info("Browser launched, continuing in %ds...", delay) - # serve prompt page - server_status, _ = self._server.serve_path( - content.root, - continue_cb=self._target.monitor.is_healthy, - server_map=srv_map, - ) - # restore server timeout - self._server.timeout = org_timeout - if server_status != Served.ALL: - self.startup_failure = True - if server_status == Served.TIMEOUT: - # this should never happen with a correctly functioning build - LOG.warning("Target hung after launch") - - if self.startup_failure: - # TODO: we need a better way to handle delayed startup failures - LOG.warning("Post launch check failed!") + assert delay >= 0 + with TestCase("post_launch_delay.html", "None") as content: + content.add_from_file( + Path(__file__).parent / "post_launch_delay.html", + file_name=content.entry_point, + copy=True, + ) + srv_map = ServerMap() + srv_map.set_redirect("grz_start", content.entry_point, required=False) + srv_map.set_redirect("grz_continue", "grz_start", required=True) + # temporarily override server timeout + org_timeout = self._server.timeout + # add time buffer to redirect delay + # in practice this should take a few seconds (~10s) + # in extreme cases ~40s (slow build + debugger) + self._server.timeout = delay + 180 + if delay > 0: + LOG.info("Browser launched, continuing in %ds...", delay) + # serve prompt page + server_status, _ = self._server.serve_path( + content.root, + continue_cb=self._target.monitor.is_healthy, + server_map=srv_map, + ) + # restore server timeout + self._server.timeout = org_timeout + if server_status != Served.ALL: + self.startup_failure = True + if server_status == Served.TIMEOUT: + # this should never happen with a correctly functioning build + LOG.warning("Target hung after launch") + LOG.warning("Post launch check failed!") def run( self, diff --git a/grizzly/common/test_reporter.py b/grizzly/common/test_reporter.py index faf829dd..34a31c14 100644 --- a/grizzly/common/test_reporter.py +++ b/grizzly/common/test_reporter.py @@ -177,7 +177,9 @@ def test_fuzzmanager_reporter_01(mocker, tmp_path, tests, frequent, force, sig_c test_cases.append(fake_test) reporter = FuzzManagerReporter("fake-tool") reporter.submit( - test_cases, Report(log_path, Path("bin"), is_hang=True), force=force + test_cases, + Report(log_path, Path("bin"), is_hang=True, unstable=True), + force=force, ) assert not log_path.is_dir() assert fake_collector.call_args == ({"tool": "fake-tool"},) diff --git a/grizzly/common/test_runner.py b/grizzly/common/test_runner.py index 8ffb6d5a..df61617d 100644 --- a/grizzly/common/test_runner.py +++ b/grizzly/common/test_runner.py @@ -44,7 +44,7 @@ def test_runner_01(mocker, coverage, scheme): testcase.add_from_bytes(b"", testcase.entry_point) serv_files = {"a.bin": testcase.root / "a.bin"} server.serve_path.return_value = (Served.ALL, serv_files) - result = runner.run([], serv_map, testcase, coverage=coverage) + result = runner.run(set(), serv_map, testcase, coverage=coverage) assert testcase.https == (scheme == "https") assert runner.initial assert runner._tests_run == 1 @@ -81,7 +81,7 @@ def test_runner_02(mocker): runner = Runner(server, target, relaunch=1) assert runner._relaunch == 1 smap = ServerMap() - result = runner.run([], smap, testcase) + result = runner.run(set(), smap, testcase) assert runner.initial assert result.attempted assert target.close.call_count == 1 @@ -100,7 +100,7 @@ def test_runner_02(mocker): target.monitor.is_idle.return_value = True runner = Runner(server, target, relaunch=1) assert runner._relaunch == 1 - result = runner.run([], ServerMap(), testcase) + result = runner.run(set(), ServerMap(), testcase) assert result.attempted assert target.close.call_count == 1 assert target.monitor.is_healthy.call_count > 0 @@ -111,7 +111,7 @@ def test_runner_02(mocker): target.monitor.is_healthy.return_value = False for _ in range(2): smap = ServerMap() - result = runner.run([], smap, testcase) + result = runner.run(set(), smap, testcase) assert result.attempted assert target.close.call_count == 0 assert target.monitor.is_healthy.call_count == 0 @@ -154,7 +154,7 @@ def test_runner_03(mocker, srv_result, served): target.check_result.return_value = Result.NONE test = mocker.Mock(spec_set=TestCase, entry_point="x", required=["x"]) runner = Runner(server, target) - result = runner.run([], ServerMap(), test) + result = runner.run(set(), ServerMap(), test) assert runner.initial assert runner.startup_failure assert result @@ -224,7 +224,7 @@ def test_runner_05(mocker, served, attempted, target_result, status): testcase = mocker.Mock(spec_set=TestCase, entry_point="a.bin", required=["a.bin"]) runner = Runner(server, target) runner.launch("http://a/") - result = runner.run([], ServerMap(), testcase) + result = runner.run(set(), ServerMap(), testcase) assert result.attempted == attempted assert result.status == status assert not result.timeout @@ -242,7 +242,7 @@ def test_runner_06(mocker): runner = Runner(server, target, idle_threshold=0.01, idle_delay=0.01, relaunch=10) assert runner._idle is not None result = runner.run( - [], + set(), ServerMap(), mocker.Mock(spec_set=TestCase, entry_point="a.bin", required=tuple(serv_files)), ) @@ -357,7 +357,7 @@ def test_runner_10(mocker, tmp_path): "test/inc_file3.txt": inc3, } server.serve_path.return_value = (Served.ALL, serv_files) - result = runner.run([], smap, test) + result = runner.run(set(), smap, test) assert result.attempted assert result.status == Result.NONE assert "inc_file.bin" in test @@ -386,7 +386,7 @@ def test_runner_11(mocker): "extra.js": test.root / "extra.js", }, ) - result = runner.run([], ServerMap(), test) + result = runner.run(set(), ServerMap(), test) assert result.attempted assert result.status == Result.NONE assert "test.html" in test @@ -401,8 +401,6 @@ def test_runner_11(mocker): (10, (Served.ALL, None), False), # continue immediately (0, (Served.ALL, None), False), - # skip post launch delay page - (-1, None, False), # startup failure (0, (Served.NONE, None), True), # target hang while loading content @@ -412,10 +410,7 @@ def test_runner_11(mocker): def test_runner_12(mocker, delay, srv_result, startup_failure): """test Runner.post_launch()""" srv_timeout = 1 - server = mocker.Mock( - spec_set=Sapphire, - timeout=srv_timeout, - ) + server = mocker.Mock(spec_set=Sapphire, timeout=srv_timeout) server.serve_path.return_value = srv_result runner = Runner(server, mocker.Mock(spec_set=Target, launch_timeout=30)) runner.launch("http://a/") diff --git a/grizzly/replay/replay.py b/grizzly/replay/replay.py index e3b4e888..b7fb390f 100644 --- a/grizzly/replay/replay.py +++ b/grizzly/replay/replay.py @@ -293,7 +293,7 @@ def run( idle_threshold: int = 0, launch_attempts: int = 3, on_iteration_cb: Optional[Callable[[], None]] = None, - post_launch_delay: int = 0, + post_launch_delay: int = -1, ) -> List[ReplayResult]: """Run testcase replay. @@ -313,7 +313,7 @@ def run( launch_attempts: Number of attempts to launch the browser. on_iteration_cb: Called every time a single iteration is run. post_launch_delay: Number of seconds to wait before continuing after the - browser is launched. + browser is launched. A negative number skips redirect. Returns: ReplayResults that were found running provided testcases. @@ -379,7 +379,8 @@ def harness_fn(_: str) -> bytes: # pragma: no cover time_limit=time_limit if self._harness else None, ) runner.launch(location, max_retries=launch_attempts) - runner.post_launch(delay=post_launch_delay) + if post_launch_delay >= 0 and not runner.startup_failure: + runner.post_launch(delay=post_launch_delay) # TODO: avoid running test case if runner.startup_failure is True # run tests durations: List[float] = [] @@ -423,12 +424,11 @@ def harness_fn(_: str) -> bytes: # pragma: no cover assert run_result is not None if not run_result.attempted: LOG.warning("Test case was not served") - if runner.initial: - if run_result.status == Result.FOUND: - # TODO: what is the best action to take in this case? - LOG.warning("Delayed startup failure detected") - else: - LOG.warning("Timeout too short? System too busy?") + if run_result.timeout: + LOG.warning("Browser hung? Timeout too short? System too busy?") + elif runner.initial: + # TODO: what is the best action to take in this case? + LOG.warning("Delayed startup failure detected") # process run results if run_result.status == Result.FOUND: report: Optional[Report] = None @@ -439,70 +439,61 @@ def harness_fn(_: str) -> bytes: # pragma: no cover log_path = Path(mkdtemp(prefix="logs_", dir=grz_tmp("logs"))) self.target.save_logs(log_path) report = Report( - log_path, self.target.binary, is_hang=run_result.timeout + log_path, + self.target.binary, + is_hang=run_result.timeout, + unstable=runner.startup_failure, ) # set active signature - if ( - not runner.startup_failure - and not self._any_crash - and not run_result.timeout - and not sig_set - ): + if not self._any_crash and not run_result.timeout and not sig_set: assert not expect_hang assert self._signature is None LOG.debug( "no signature given, using short sig %r", report.short_signature, ) + if runner.startup_failure: + LOG.warning( + "Using signature from startup failure! " + "Provide a signature to avoid this." + ) self._signature = report.crash_signature sig_set = True if self._signature is not None: assert not sig_hash, "sig_hash should only be set once" sig_hash = Report.calc_hash(self._signature) - - # bucket result - if not runner.startup_failure and ( - self._any_crash - or self.check_match( - self._signature, report, expect_hang, sig_set - ) - ): + # look for existing buckets (signature match) + expected = self._any_crash or self.check_match( + self._signature, report, expect_hang, sig_set + ) + if expected: if sig_hash is not None: LOG.debug("using signature hash (%s) to bucket", sig_hash) bucket_hash = sig_hash else: bucket_hash = report.crash_hash self.status.results.count(bucket_hash, report.short_signature) - LOG.info( - "Result: %s (%s:%s)", - report.short_signature, - report.major[:8], - report.minor[:8], - ) - if bucket_hash not in reports: - reports[bucket_hash] = ReplayResult(report, durations, True) - LOG.debug("now tracking %s", bucket_hash) - report = None # don't remove report - else: - reports[bucket_hash].count += 1 - LOG.debug("already tracking %s", bucket_hash) else: - LOG.info( - "Result: Different signature: %s (%s:%s)", - report.short_signature, - report.major[:8], - report.minor[:8], - ) + bucket_hash = report.crash_hash self.status.ignored += 1 - if report.crash_hash not in reports: - reports[report.crash_hash] = ReplayResult( - report, durations, False - ) - LOG.debug("now tracking %s", report.crash_hash) - report = None # don't remove report - else: - reports[report.crash_hash].count += 1 - LOG.debug("already tracking %s", report.crash_hash) + LOG.info( + "%s: %s (%s:%s)", + "Result" if expected else "Result: Different signature", + report.short_signature, + report.major[:8], + report.minor[:8], + ) + # bucket result + if bucket_hash not in reports: + reports[bucket_hash] = ReplayResult(report, durations, expected) + LOG.debug("now tracking %s", bucket_hash) + report = None # don't remove report + else: + reports[bucket_hash].count += 1 + if report.unstable and not reports[bucket_hash].report.unstable: + LOG.debug("updating report to unstable") + reports[bucket_hash].report.unstable = True + LOG.debug("already tracking %s", bucket_hash) # purge untracked report if report is not None: report.cleanup() @@ -554,17 +545,10 @@ def harness_fn(_: str) -> bytes: # pragma: no cover # process results if self._any_crash: - # add all results if min_results was reached - if sum(x.count for x in reports.values() if x.expected) >= min_results: - results: List[ReplayResult] = list(reports.values()) - else: - # add only unexpected results since min_results was not reached - results = [] - for result in reports.values(): - if result.expected: - result.report.cleanup() - else: - results.append(result) + # all reports should be expected when self._any_crash=True + assert all(x.expected for x in reports.values()) + success = sum(x.count for x in reports.values()) >= min_results + if not success: LOG.debug( "%d (any_crash) less than minimum %d", self.status.results.total, @@ -573,19 +557,24 @@ def harness_fn(_: str) -> bytes: # pragma: no cover else: # there should be at most one expected bucket assert sum(x.expected for x in reports.values()) <= 1 - # filter out unreliable expected results - results = [] - for crash_hash, result in reports.items(): - if result.expected and result.count < min_results: + success = any( + x.count >= min_results for x in reports.values() if x.expected + ) + results: List[ReplayResult] = [] + for crash_hash, result in reports.items(): + # if min_results not met (success=False) cleanup expected reports + if not success and result.expected: + if not self._any_crash: LOG.debug( "%r less than minimum (%d/%d)", crash_hash, result.count, min_results, ) - result.report.cleanup() - continue - results.append(result) + result.report.cleanup() + continue + results.append(result) + # this should only be displayed when both conditions are met: # 1) runner does not close target (no delay was given before shutdown) # 2) result has not been successfully reproduced @@ -601,7 +590,7 @@ def harness_fn(_: str) -> bytes: # pragma: no cover return results finally: - # we don't want to clean up but we are not checking results + # we don't want to cleanup but we are not checking results self.target.close(force_close=True) # remove unprocessed reports for result in reports.values(): diff --git a/grizzly/replay/test_replay.py b/grizzly/replay/test_replay.py index 721b62c5..94ab2a38 100644 --- a/grizzly/replay/test_replay.py +++ b/grizzly/replay/test_replay.py @@ -33,24 +33,21 @@ def _fake_save_logs(result_logs): log_fp.write(" #1 0x1337dd in bar /file2.c:1806:19\n") -def test_replay_01(mocker, server, tmp_path): +@mark.parametrize("post_launch_delay", [0, -1]) +def test_replay_01(mocker, server, tmp_path, post_launch_delay): """test ReplayManager.run() - no repro""" target = mocker.Mock(spec_set=Target, closed=True, launch_timeout=30) target.check_result.return_value = Result.NONE target.monitor.is_healthy.return_value = False - iter_cb = mocker.Mock() - (tmp_path / "test.html").touch() - server.serve_path.return_value = ( - Served.ALL, - {"test.html": str(tmp_path / "test.html")}, - ) + (tmp_path / "a.html").touch() + server.serve_path.return_value = (Served.ALL, {"a.html": str(tmp_path / "a.html")}) with TestCase.load(tmp_path) as testcase: with ReplayManager([], server, target, use_harness=True, relaunch=1) as replay: - assert not replay.run([testcase], 10, on_iteration_cb=iter_cb) + assert not replay.run([testcase], 10, post_launch_delay=post_launch_delay) assert replay.signature is None assert replay.status assert replay.status.ignored == 0 - assert replay.status.iteration == iter_cb.call_count == 1 + assert replay.status.iteration == 1 assert replay.status.results.total == 0 assert target.monitor.is_healthy.call_count == 1 assert target.close.call_count == 2 @@ -66,16 +63,11 @@ def test_replay_02(mocker, server, tmp_path): target.check_result.return_value = Result.NONE target.monitor.is_healthy.return_value = False iter_cb = mocker.Mock() - (tmp_path / "test.html").touch() - server.serve_path.return_value = ( - Served.ALL, - {"test.html": str(tmp_path / "test.html")}, - ) + (tmp_path / "a.html").touch() + server.serve_path.return_value = (Served.ALL, {"a.html": str(tmp_path / "a.html")}) with TestCase.load(tmp_path) as testcase: with ReplayManager([], server, target, use_harness=True, relaunch=20) as replay: - assert not replay.run( - [testcase], 10, repeat=10, min_results=1, on_iteration_cb=iter_cb - ) + assert not replay.run([testcase], 10, repeat=10, on_iteration_cb=iter_cb) assert replay.signature is None assert replay.status assert replay.status.ignored == 0 @@ -97,11 +89,8 @@ def test_replay_03(mocker, server, tmp_path): ) target = mocker.Mock(spec_set=Target, closed=False, launch_timeout=30) target.check_result.return_value = Result.NONE - (tmp_path / "test.html").touch() - server.serve_path.return_value = ( - Served.ALL, - {"test.html": str(tmp_path / "test.html")}, - ) + (tmp_path / "a.html").touch() + server.serve_path.return_value = (Served.ALL, {"a.html": str(tmp_path / "a.html")}) with TestCase.load(tmp_path) as testcase: with ReplayManager([], server, target, use_harness=True, relaunch=20) as replay: assert not replay.run([testcase], 10, repeat=10, min_results=1) @@ -114,21 +103,14 @@ def test_replay_03(mocker, server, tmp_path): assert target.close.call_count == 1 -@mark.parametrize( - "good_sig", - [ - # success - FM parsed signature - True, - # signature could not be parsed - False, - ], -) -def test_replay_04(mocker, server, tmp_path, good_sig): +@mark.parametrize("sig_parsed", [True, False]) +@mark.parametrize("post_launch_delay", [0, -1]) +def test_replay_04(mocker, server, tmp_path, sig_parsed, post_launch_delay): """test ReplayManager.run() - successful repro""" target = mocker.Mock(spec_set=Target, binary=Path("bin"), launch_timeout=30) target.check_result.return_value = Result.FOUND target.monitor.is_healthy.return_value = False - if good_sig: + if sig_parsed: target.save_logs = _fake_save_logs else: @@ -139,16 +121,13 @@ def _save_logs(result_logs): (log_path / "log_stdout.txt").write_text("STDOUT log\n") target.save_logs = _save_logs - (tmp_path / "test.html").touch() - server.serve_path.return_value = ( - Served.ALL, - {"test.html": str(tmp_path / "test.html")}, - ) + (tmp_path / "a.html").touch() + server.serve_path.return_value = (Served.ALL, {"a.html": str(tmp_path / "a.html")}) with TestCase.load(tmp_path) as testcase: with ReplayManager([], server, target, relaunch=10) as replay: assert replay.signature is None - results = replay.run([testcase], 10) - if good_sig: + results = replay.run([testcase], 10, post_launch_delay=post_launch_delay) + if sig_parsed: assert replay.signature is not None else: assert replay.signature is None @@ -185,21 +164,6 @@ def test_replay_05(mocker, server): # target.close() called once in runner and once by ReplayManager.run() assert target.close.call_count == 2 target.reset_mock() - # test target crashed - target.check_result.return_value = Result.FOUND - target.save_logs = _fake_save_logs - with ReplayManager([], server, target, use_harness=False) as replay: - results = replay.run(tests, 10, repeat=1) - assert replay.status - assert replay.status.ignored == 1 - assert replay.status.iteration == 1 - assert replay.status.results.total == 0 - assert replay._signature is None - # target.close() called once in runner and once by ReplayManager.run() - assert target.close.call_count == 2 - assert len(results) == 1 - assert results[0].count == 1 - assert not results[0].expected def test_replay_06(mocker, server): @@ -216,7 +180,7 @@ def test_replay_06(mocker, server): (Served.REQUEST, {"x": "/fake/path"}), ) with ReplayManager([], server, target, use_harness=True, relaunch=10) as replay: - assert replay.run(tests, 10, repeat=2, post_launch_delay=-1) + assert replay.run(tests, 10, repeat=2) assert replay.status assert replay.status.ignored == 0 assert replay.status.iteration == 2 @@ -429,23 +393,59 @@ def test_replay_12(mocker, server): assert report_2.cleanup.call_count == 1 -def test_replay_13(mocker, server): - """test ReplayManager.run() - any crash - startup failure""" - server.serve_path.return_value = (Served.NONE, {}) +@mark.parametrize( + "to_serve, sig_value, expected, unexpected", + [ + # No signature provided + (((Served.NONE, {}), (Served.ALL, {"a.html": "/fake/path"})), None, 2, 0), + (((Served.ALL, {"a.html": "/fake/path"}), (Served.NONE, {})), None, 2, 0), + (((Served.NONE, {}), (Served.NONE, {})), None, 2, 0), + # Signature provided (signatures match) + (((Served.NONE, {}), (Served.ALL, {"a.html": "/fake/path"})), "STDERR", 2, 0), + (((Served.ALL, {"a.html": "/fake/path"}), (Served.NONE, {})), "STDERR", 2, 0), + (((Served.NONE, {}), (Served.NONE, {})), "STDERR", 2, 0), + # Signature provided (signatures don't match) + (((Served.NONE, {}), (Served.ALL, {"a.html": "/fake/path"})), "miss", 0, 1), + (((Served.ALL, {"a.html": "/fake/path"}), (Served.NONE, {})), "miss", 0, 1), + (((Served.NONE, {}), (Served.NONE, {})), "miss", 0, 1), + # Hang after launch, before first test + (((Served.TIMEOUT, {}),), None, 0, 0), + ], +) +def test_replay_13(mocker, server, tmp_path, to_serve, sig_value, expected, unexpected): + """test ReplayManager.run() - result after launch, before running test""" + server.serve_path.side_effect = to_serve + + # prepare signature + if sig_value is not None: + sig_file = tmp_path / "sig.json" + sig_file.write_text( + "{\n" + ' "symptoms": [\n' + " {\n" + ' "src": "stderr",\n' + ' "type": "output",\n' + f' "value": "/{sig_value}/"\n' + " }\n" + " ]\n" + "}\n" + ) + sig = CrashSignature.fromFile(str(sig_file)) + else: + sig = None + target = mocker.Mock(spec_set=Target, binary=Path("bin"), launch_timeout=30) target.check_result.return_value = Result.FOUND target.save_logs = _fake_save_logs target.monitor.is_healthy.return_value = False tests = [mocker.MagicMock(spec_set=TestCase, entry_point="a.html")] - with ReplayManager([], server, target, any_crash=True, use_harness=False) as replay: - results = replay.run(tests, 10, repeat=1, min_results=1) - assert results - assert not any(x.expected for x in results) - assert target.close.call_count == 2 - assert replay.status - assert replay.status.iteration == 1 - assert replay.status.results.total == 0 - assert replay.status.ignored == 1 + with ReplayManager(set(), server, target, any_crash=False, signature=sig) as replay: + assert replay._relaunch == 1, "test is broken!" + results = replay.run(tests, 10, repeat=2, min_results=2) + assert sum(x.count for x in results if x.expected) == expected + assert sum(x.count for x in results if not x.expected) == unexpected + # make sure the serve flag is updated + assert any(x.report.unstable for x in results) or expected == 0 def test_replay_14(mocker, server): @@ -500,7 +500,7 @@ def test_replay_15(mocker, server): [], server, target, any_crash=True, use_harness=True, relaunch=2 ) as replay: with raises(KeyboardInterrupt): - replay.run(tests, 10, repeat=3, min_results=2, post_launch_delay=-1) + replay.run(tests, 10, repeat=3, min_results=2) assert replay.signature is None assert replay.status assert replay.status.iteration == 2 @@ -542,7 +542,7 @@ def test_replay_17(mocker, server): mocker.MagicMock(spec_set=TestCase, entry_point="a.html") for _ in range(3) ] with ReplayManager([], server, target, use_harness=True, relaunch=2) as replay: - assert not replay.run(tests, 10, repeat=10, post_launch_delay=-1) + assert not replay.run(tests, 10, repeat=10) assert server.serve_path.call_count == 30 assert target.close.call_count == 6 assert target.launch.call_count == 5 @@ -572,7 +572,7 @@ def test_replay_18(mocker, server): mocker.MagicMock(spec_set=TestCase, entry_point=f"{i}.html") for i in range(3) ] with ReplayManager([], server, target, use_harness=True) as replay: - results = replay.run(tests, 30, post_launch_delay=-1) + results = replay.run(tests, 30) assert target.close.call_count == 2 assert replay.status assert replay.status.ignored == 0 @@ -595,13 +595,13 @@ def test_replay_19(mocker, server, tmp_path): ) with TestCase.load(tmp_path) as testcase: with ReplayManager([], server, target, use_harness=True) as replay: - assert not replay.run([testcase], 30, post_launch_delay=-1) + assert not replay.run([testcase], 30) assert replay.status assert replay.status.iteration == 1 - assert not replay.run([testcase], 30, post_launch_delay=-1) + assert not replay.run([testcase], 30) assert replay.status assert replay.status.iteration == 1 - assert not replay.run([testcase], 30, post_launch_delay=-1) + assert not replay.run([testcase], 30) assert replay.status assert replay.status.iteration == 1 assert server.serve_path.call_count == 3 @@ -736,7 +736,7 @@ def test_replay_23( target.monitor.is_healthy.return_value = False test = mocker.MagicMock(spec_set=TestCase, entry_point="a.html", hang=is_hang) with ReplayManager([], server, target, signature=signature, relaunch=10) as replay: - found = replay.run([test], 10, expect_hang=expect_hang, post_launch_delay=-1) + found = replay.run([test], 10, expect_hang=expect_hang) assert replay.status assert replay.status.iteration == 1 assert replay.status.ignored == ignored @@ -810,11 +810,8 @@ def _save_logs_variation(result_logs): target.save_logs.side_effect = _save_logs_variation - (tmp_path / "test.html").touch() - server.serve_path.return_value = ( - Served.ALL, - {"test.html": str(tmp_path / "test.html")}, - ) + (tmp_path / "a.html").touch() + server.serve_path.return_value = (Served.ALL, {"a.html": str(tmp_path / "a.html")}) with TestCase.load(tmp_path) as testcase: with ReplayManager([], server, target, relaunch=10, signature=sig) as replay: results = replay.run([testcase], 10, min_results=2, repeat=2) @@ -879,11 +876,8 @@ def _save_logs_variation(result_logs): target.save_logs.side_effect = _save_logs_variation has_sig = include_stack[0] - (tmp_path / "test.html").touch() - server.serve_path.return_value = ( - Served.ALL, - {"test.html": str(tmp_path / "test.html")}, - ) + (tmp_path / "a.html").touch() + server.serve_path.return_value = (Served.ALL, {"a.html": str(tmp_path / "a.html")}) with TestCase.load(tmp_path) as testcase: with ReplayManager([], server, target, relaunch=10) as replay: results = replay.run([testcase], 10, min_results=2, repeat=iters) @@ -924,7 +918,7 @@ def test_replay_27(mocker, server, tmp_path): ) with ReplayManager([], server, target, use_harness=True) as replay: assert "include.js" not in test - results = replay.run([test], 30, post_launch_delay=-1) + results = replay.run([test], 30) assert replay.status assert replay.status.ignored == 0 assert replay.status.iteration == 1 diff --git a/grizzly/session.py b/grizzly/session.py index ea922275..30709441 100644 --- a/grizzly/session.py +++ b/grizzly/session.py @@ -215,7 +215,8 @@ def run( ) with self.status.measure("launch"): runner.launch(location, max_retries=launch_attempts, retry_delay=0) - runner.post_launch(delay=post_launch_delay) + if post_launch_delay >= 0 and not runner.startup_failure: + runner.post_launch(delay=post_launch_delay) # TODO: avoid running test case if runner.startup_failure is True # especially if it is a hang! @@ -246,21 +247,24 @@ def run( if current_test.entry_point not in current_test: LOG.error("Check adapter, test case is missing entry point") raise SessionError("Test case is missing entry point") - if runner.initial and result.status != Result.NONE: + if result.timeout: + LOG.warning("Browser hung? Timeout too short? System too busy?") + elif runner.initial: # since this is the first iteration since the Target launched # something is likely wrong with the Target or Adapter LOG.warning( "Failure detected before running a test case, " "browser build is potentially unstable" ) - if result.timeout: - LOG.warning("Browser hung? Timeout too short? System too busy?") else: self.iomanager.commit() # process results if result.status == Result.FOUND: LOG.debug("result detected") - report = self.target.create_report(is_hang=result.timeout) + report = self.target.create_report( + is_hang=result.timeout, + unstable=runner.startup_failure, + ) seen, initial = self.status.results.count( report.crash_hash, report.short_signature ) diff --git a/grizzly/target/puppet_target.py b/grizzly/target/puppet_target.py index 5f4c498e..a4cda8b8 100644 --- a/grizzly/target/puppet_target.py +++ b/grizzly/target/puppet_target.py @@ -153,10 +153,10 @@ def close(self, force_close: bool = False) -> None: def closed(self) -> bool: return self._puppet.reason is not None - def create_report(self, is_hang: bool = False) -> Report: + def create_report(self, is_hang: bool = False, unstable: bool = False) -> Report: logs = Path(mkdtemp(prefix="logs_", dir=grz_tmp("logs"))) self.save_logs(logs) - return Report(logs, self.binary, is_hang=is_hang) + return Report(logs, self.binary, is_hang=is_hang, unstable=unstable) def filtered_environ(self) -> Dict[str, str]: # remove context specific entries from environment @@ -362,7 +362,9 @@ def launch(self, location: str) -> None: self.close() if isinstance(exc, BrowserTimeoutError): raise TargetLaunchTimeout(str(exc)) from None - raise TargetLaunchError(str(exc), self.create_report()) from None + raise TargetLaunchError( + str(exc), self.create_report(unstable=True) + ) from None def log_size(self) -> int: total = 0 diff --git a/grizzly/target/target.py b/grizzly/target/target.py index 582743fb..93a62e3c 100644 --- a/grizzly/target/target.py +++ b/grizzly/target/target.py @@ -179,11 +179,12 @@ def closed(self) -> bool: """ @abstractmethod - def create_report(self, is_hang: bool = False) -> Report: + def create_report(self, is_hang: bool = False, unstable: bool = False) -> Report: """Process logs and create a Report. Args: is_hang: Indicate whether the results is due to a hang/timeout. + unstable: Indicate whether build is unstable. Returns: Report object. diff --git a/grizzly/target/test_target.py b/grizzly/target/test_target.py index d8849ad2..04c0a553 100644 --- a/grizzly/target/test_target.py +++ b/grizzly/target/test_target.py @@ -21,7 +21,7 @@ def close(self, force_close=False): def closed(self): return True - def create_report(self, is_hang=False): + def create_report(self, is_hang=False, unstable=False): pass def dump_coverage(self, timeout=0):