From 6fb00f32cab163cbed1f6888cdb92cd71856e9ac Mon Sep 17 00:00:00 2001 From: Tyson Smith Date: Tue, 24 Mar 2026 15:46:40 -0700 Subject: [PATCH 1/5] fix(replay): simplify report handling --- src/grizzly/replay/replay.py | 7 +------ 1 file changed, 1 insertion(+), 6 deletions(-) diff --git a/src/grizzly/replay/replay.py b/src/grizzly/replay/replay.py index 69d3d0c5..08bc1681 100644 --- a/src/grizzly/replay/replay.py +++ b/src/grizzly/replay/replay.py @@ -58,7 +58,6 @@ class ReplayManager: "_harness", "_relaunch", "_signature", - "_unpacked", "ignore", "server", "status", @@ -376,7 +375,6 @@ def harness_fn(_: str) -> bytes: # pragma: no cover LOG.warning("Delayed startup failure detected") # process run results if run_result.status == Result.FOUND: - report: Report | None = None # processing the result may take a few minutes (rr) # update console to show progress LOG.info("Processing result...") @@ -432,17 +430,14 @@ def harness_fn(_: str) -> bytes: # pragma: no cover 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: + # remove duplicate report report.cleanup() - report = None elif run_result.status == Result.IGNORED: self.status.ignored += 1 if run_result.timeout: From 6844fef6de6accf18ec56a19e443c21e6b6a9d6b Mon Sep 17 00:00:00 2001 From: Tyson Smith Date: Tue, 24 Mar 2026 16:30:04 -0700 Subject: [PATCH 2/5] fix(replay): create ReplayManager._setup_server_map() --- src/grizzly/replay/replay.py | 46 ++++++++++++++++++------------- src/grizzly/replay/test_replay.py | 40 +++++++++++++++++++++++++++ 2 files changed, 67 insertions(+), 19 deletions(-) diff --git a/src/grizzly/replay/replay.py b/src/grizzly/replay/replay.py index 08bc1681..01e21a90 100644 --- a/src/grizzly/replay/replay.py +++ b/src/grizzly/replay/replay.py @@ -221,6 +221,32 @@ def report_to_fuzzmanager( # avoid reporting unexpected frequent results reporter.submit(tests, result.report, force=result.expected) + def _setup_server_map(self, services: WebServices | None = None) -> ServerMap: + """Create and configure a ServerMap for the replay session. + Configures the start redirect to point at either the harness or the + current test directly and registers any additional service locations. + + Args: + services: Optional WebServices whose locations should be added to the map. + + Returns: + Configured ServerMap. + """ + server_map = ServerMap() + if self._harness is None: + server_map.set_redirect("grz_start", "grz_current_test", required=False) + else: + harness = self._harness + server_map.set_dynamic_response( + "grz_harness", + lambda _: harness, + mime_type="text/html", + ) + server_map.set_redirect("grz_start", "grz_harness", required=False) + if services: + services.map_locations(server_map) + return server_map + def run( self, testcases: list[TestCase], @@ -273,25 +299,7 @@ def run( self.status = SimpleStatus.start() - server_map = ServerMap() - if self._harness is None: - server_map.set_redirect("grz_start", "grz_current_test", required=False) - else: - assert self._harness, "harness must contain data" - - def harness_fn(_: str) -> bytes: # pragma: no cover - assert self._harness - return self._harness - - server_map.set_dynamic_response( - "grz_harness", - harness_fn, - mime_type="text/html", - ) - server_map.set_redirect("grz_start", "grz_harness", required=False) - - if services: - services.map_locations(server_map) + server_map = self._setup_server_map(services) # track unprocessed results reports: dict[str, ReplayResult] = {} diff --git a/src/grizzly/replay/test_replay.py b/src/grizzly/replay/test_replay.py index de8df466..375aed96 100644 --- a/src/grizzly/replay/test_replay.py +++ b/src/grizzly/replay/test_replay.py @@ -1004,3 +1004,43 @@ def test_replay_28(mocker, adapters, expected): """test ReplayManager.lookup_tool()""" testcases = [mocker.Mock(spec_set=TestCase, adapter_name=name) for name in adapters] assert ReplayManager.lookup_tool(testcases) == expected + + +def test_replay_29(mocker, server): + """test ReplayManager._setup_server_map()""" + target = mocker.Mock(spec_set=Target, closed=True, launch_timeout=30) + sm_cls = mocker.patch("grizzly.replay.replay.ServerMap", autospec=True) + + # without harness - redirects directly to current test + with ReplayManager([], server, target, use_harness=False) as replay: + result = replay._setup_server_map() + assert result is sm_cls.return_value + sm_cls.return_value.set_redirect.assert_called_once_with( + "grz_start", "grz_current_test", required=False + ) + sm_cls.return_value.set_dynamic_response.assert_not_called() + sm_cls.reset_mock() + + # with harness - serves harness file and redirects to it + with ReplayManager([], server, target, use_harness=True) as replay: + harness_content = replay._harness + result = replay._setup_server_map() + assert result is sm_cls.return_value + sm_cls.return_value.set_dynamic_response.assert_called_once() + name, fn = sm_cls.return_value.set_dynamic_response.call_args[0] + assert name == "grz_harness" + assert ( + sm_cls.return_value.set_dynamic_response.call_args[1]["mime_type"] + == "text/html" + ) + assert fn(None) == harness_content + sm_cls.return_value.set_redirect.assert_called_once_with( + "grz_start", "grz_harness", required=False + ) + sm_cls.reset_mock() + + # with services - locations are mapped onto the server map + services = mocker.Mock() + with ReplayManager([], server, target, use_harness=False) as replay: + result = replay._setup_server_map(services) + services.map_locations.assert_called_once_with(sm_cls.return_value) From dd3b282dc8e70cd16751f2cf73b8a3a42a0787f6 Mon Sep 17 00:00:00 2001 From: Tyson Smith Date: Tue, 24 Mar 2026 18:02:24 -0700 Subject: [PATCH 3/5] fix(replay): create ReplayManager._process_reports() --- src/grizzly/replay/replay.py | 104 +++++++++++++++++------------- src/grizzly/replay/test_replay.py | 90 ++++++++++++++++++++++++++ 2 files changed, 149 insertions(+), 45 deletions(-) diff --git a/src/grizzly/replay/replay.py b/src/grizzly/replay/replay.py index 01e21a90..a2fd48a9 100644 --- a/src/grizzly/replay/replay.py +++ b/src/grizzly/replay/replay.py @@ -247,6 +247,64 @@ def _setup_server_map(self, services: WebServices | None = None) -> ServerMap: services.map_locations(server_map) return server_map + def _process_reports( + self, + reports: dict[str, ReplayResult], + min_results: int, + ) -> list[ReplayResult]: + """Collect results and cleanup remaining reports. + + Args: + reports: Accumulated ReplayResults bucketed by hash. + min_results: Minimum results required for success. + + Returns: + ReplayResults that meet the minimum required threshold. + """ + if self._any_crash: + # 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: + assert self.status is not None + LOG.debug( + "%d (any_crash) less than minimum %d", + self.status.results.total, + min_results, + ) + else: + # there should be at most one expected bucket + assert sum(x.expected for x in reports.values()) <= 1 + 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( + "'%s' less than minimum (%d/%d)", + crash_hash, + result.count, + min_results, + ) + 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 + if ( + self._relaunch > 1 + and not self.target.closed + and not any(x.expected for x in results) + ): + LOG.info("Perhaps try with --relaunch=1") + # active reports have been moved to results clear reports collection + reports.clear() + return results + def run( self, testcases: list[TestCase], @@ -491,51 +549,7 @@ def run( # TODO: should we warn about large browser logs? - # process results - if self._any_crash: - # 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, - min_results, - ) - else: - # there should be at most one expected bucket - assert sum(x.expected for x in reports.values()) <= 1 - 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( - "'%s' less than minimum (%d/%d)", - crash_hash, - result.count, - min_results, - ) - 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 - if ( - self._relaunch > 1 - and not self.target.closed - and not any(x.expected for x in results) - ): - LOG.info("Perhaps try with --relaunch=1") - # active reports have been moved to results - # clear reports to avoid cleanup of active reports - reports.clear() - return results + return self._process_reports(reports, min_results) finally: # we don't want to cleanup but we are not checking results diff --git a/src/grizzly/replay/test_replay.py b/src/grizzly/replay/test_replay.py index 375aed96..ffdfe6ba 100644 --- a/src/grizzly/replay/test_replay.py +++ b/src/grizzly/replay/test_replay.py @@ -4,6 +4,7 @@ # pylint: disable=protected-access from itertools import cycle +from logging import INFO from pathlib import Path from FTB.Signatures.CrashInfo import CrashSignature @@ -1044,3 +1045,92 @@ def test_replay_29(mocker, server): with ReplayManager([], server, target, use_harness=False) as replay: result = replay._setup_server_map(services) services.map_locations.assert_called_once_with(sm_cls.return_value) + + +@mark.parametrize( + "any_crash, count, min_results, success", + [ + # any_crash=True, count meets minimum + (True, 2, 2, True), + # any_crash=True, count below minimum + (True, 1, 2, False), + # any_crash=False, count meets minimum + (False, 2, 2, True), + # any_crash=False, count below minimum + (False, 1, 2, False), + ], +) +def test_replay_30(mocker, server, any_crash, count, min_results, success): + """test ReplayManager._process_reports()""" + target = mocker.Mock(spec_set=Target, closed=True, launch_timeout=30) + with ReplayManager([], server, target, use_harness=False) as replay: + replay._any_crash = any_crash + replay.status = mocker.Mock() + replay.status.results.total = count + exp = mocker.Mock(spec_set=ReplayResult, expected=True, count=count) + unexp = None + reports = {"aaa": exp} + if not any_crash: + unexp = mocker.Mock(spec_set=ReplayResult, expected=False, count=1) + reports["bbb"] = unexp + results = replay._process_reports(reports, min_results) + if success: + assert exp in results + exp.report.cleanup.assert_not_called() + else: + assert exp not in results + exp.report.cleanup.assert_called_once() + if unexp is not None: + assert unexp in results + unexp.report.cleanup.assert_not_called() + + +def test_replay_31(mocker, server): + """test ReplayManager._process_reports() - empty reports returns empty list""" + target = mocker.Mock(spec_set=Target, closed=True, launch_timeout=30) + with ReplayManager([], server, target, use_harness=False) as replay: + replay._any_crash = False + results = replay._process_reports({}, 1) + assert not results + + +def test_replay_32(mocker, server): + """test ReplayManager._process_reports() - any_crash=True, + multiple buckets summing to min + """ + target = mocker.Mock(spec_set=Target, closed=True, launch_timeout=30) + with ReplayManager([], server, target, use_harness=False) as replay: + replay._any_crash = True + replay.status = mocker.Mock() + exp_a = mocker.Mock(spec_set=ReplayResult, expected=True, count=1) + exp_b = mocker.Mock(spec_set=ReplayResult, expected=True, count=1) + results = replay._process_reports({"aaa": exp_a, "bbb": exp_b}, 2) + assert exp_a in results + assert exp_b in results + exp_a.report.cleanup.assert_not_called() + exp_b.report.cleanup.assert_not_called() + + +def test_replay_33(mocker, server): + """test ReplayManager._process_reports() - any_crash=False, no expected bucket""" + target = mocker.Mock(spec_set=Target, closed=True, launch_timeout=30) + with ReplayManager([], server, target, use_harness=False) as replay: + replay._any_crash = False + unexp = mocker.Mock(spec_set=ReplayResult, expected=False, count=1) + results = replay._process_reports({"aaa": unexp}, 1) + assert unexp in results + unexp.report.cleanup.assert_not_called() + + +def test_replay_34(mocker, server, caplog): + """test ReplayManager._process_reports() - relaunch hint when target still open""" + target = mocker.Mock(spec_set=Target, closed=False, launch_timeout=30) + with ReplayManager([], server, target, use_harness=False) as replay: + # set _relaunch directly to avoid the use_harness/relaunch assert + replay._relaunch = 2 + replay._any_crash = False + unexp = mocker.Mock(spec_set=ReplayResult, expected=False, count=1) + with caplog.at_level(INFO, logger="grizzly.replay.replay"): + results = replay._process_reports({"aaa": unexp}, 2) + assert unexp in results + assert "relaunch=1" in caplog.text From c58f8074f94fc9c84b7743baac21a16b24f51be7 Mon Sep 17 00:00:00 2001 From: Tyson Smith Date: Wed, 25 Mar 2026 11:04:07 -0700 Subject: [PATCH 4/5] fix(common): split out log detection from Report --- src/grizzly/common/report.py | 340 +++++++++++++------------- src/grizzly/common/test_report.py | 380 +++++++++++++++--------------- 2 files changed, 362 insertions(+), 358 deletions(-) diff --git a/src/grizzly/common/report.py b/src/grizzly/common/report.py index b6b7f4a9..d6d82e95 100644 --- a/src/grizzly/common/report.py +++ b/src/grizzly/common/report.py @@ -13,9 +13,8 @@ from shutil import copyfileobj, move, rmtree from tempfile import mkstemp from time import strftime -from typing import NamedTuple +from typing import TYPE_CHECKING -# import FuzzManager utilities from Collector.Collector import Collector from FTB.ProgramConfiguration import ProgramConfiguration from FTB.Signatures.CrashInfo import CrashInfo, CrashSignature, TraceParsingError @@ -23,21 +22,185 @@ from .stack_hasher import IGNORED_FRAMES, Stack from .utils import grz_tmp -__all__ = ("Report",) +if TYPE_CHECKING: + from collections.abc import Iterator + __author__ = "Tyson Smith" __credits__ = ["Tyson Smith"] LOG = getLogger(__name__) -# NOTE: order matters, aux -> stderr -> stdout -class LogMap(NamedTuple): - aux: Path | None - stderr: Path | None - stdout: Path | None +class LogMap: + """Container mapping the three standard log file paths (aux, stderr, stdout) + produced by a target.""" + + __slots__ = ("aux", "stderr", "stdout") + + def __init__( + self, + aux: Path | None, + stderr: Path | None, + stdout: Path | None, + ) -> None: + self.aux = aux + self.stderr = stderr + self.stdout = stdout + + def __iter__(self) -> Iterator[Path | None]: + yield self.aux + yield self.stderr + yield self.stdout + + @classmethod + def create(cls, path: Path) -> LogMap: + """Scan path for file containing stderr, stdout and crashdata (aux) + and build a LogMap. + + Args: + path: Location to scan for log files. + + Returns: + A LogMap pointing to log files. + """ + files = (x for x in path.iterdir() if x.is_file()) + # order by date hopefully the oldest log is the cause of the issue + to_scan = sorted(files, key=lambda x: x.stat().st_mtime) + # look for file to use as aux log + log_aux = cls._find_sanitizer(to_scan) + if log_aux is None: + log_aux = cls._find_valgrind(to_scan) + if log_aux is None: + log_aux = cls._find_minidump(to_scan) + if log_aux is None: + log_aux = cls._find_ffpuppet_worker(to_scan) + # look for stderr and stdout log files + log_err = None + log_out = None + for log_file in to_scan: + if "stderr" in log_file.name: + log_err = log_file + elif "stdout" in log_file.name: + log_out = log_file + return cls(log_aux, log_err, log_out) + + @staticmethod + def _find_ffpuppet_worker(logs: list[Path]) -> Path | None: + """Search through list of log files for a ffpuppet worker log. + + Args: + logs: List of log files to search. + + Returns: + Log file if a match is found otherwise None. + """ + found = None + for log_file in (x for x in logs if "ffp_worker" in x.name): + if found is not None: + # we only expect one log here... + LOG.warning("overwriting previously selected '%s'", log_file) + found = log_file + return found + + @staticmethod + def _find_minidump(logs: list[Path]) -> Path | None: + """Search through list of log files for a minidump log. + + Args: + logs: List of log files to search. + + Returns: + Log file if a match is found otherwise None. + """ + re_dump_req = re_compile( + r"\d+\|0\|.+?\|google_breakpad::ExceptionHandler::WriteMinidump" + ) + for log_file in (x for x in logs if "minidump" in x.name): + with log_file.open() as log_fp: + data = log_fp.read(65536) + # this will select log that contains "Crash|SIGSEGV|" or + # the desired "DUMP_REQUESTED" log + # TODO: review this it may be too strict + # see mozilla-central/source/accessible/ipc/DocAccessibleParent.cpp#452 + if "Crash|DUMP_REQUESTED|" not in data or re_dump_req.search(data): + return log_file + return None + + @staticmethod + def _find_sanitizer(logs: list[Path]) -> Path | None: + """Search through list of log files for a sanitizer (ASan, UBSan, etc...) log. + + Args: + logs: List of log files to search. + + Returns: + Log file if a match is found otherwise None. + """ + # pattern to identify the ASan crash triggered when the parent process goes away + # TODO: this may no longer be required + re_e10s_forced = re_compile( + r""" + ==\d+==ERROR:.+?SEGV\son.+?0x[0]+\s\(.+?T2\).+? + #0\s+0x[0-9a-f]+\sin\s+mozilla::ipc::MessageChannel::OnChannelErrorFromLink + """, + DOTALL | VERBOSE, + ) + # this is a list of Sanitizer error reports to prioritize + # Sanitizer reports not included below are deprioritized + prioritize_tokens = ( + "use-after-", + "-buffer-overflow on", + ": data race ", + ": SEGV on ", + "access-violation on ", + "attempting free on ", + "negative-size-param", + "-param-overlap", + ) + fallback = None + found = None + for log_file in (x for x in logs if "asan" in x.name): + with log_file.open() as log_fp: + data = log_fp.read(65536) + # look for interesting crash info in the log + if "==ERROR:" in data or "WARNING:" in data: + # check for e10s forced crash + if re_e10s_forced.search(data) is not None: + continue + # make sure there is something that looks like a stack frame + if "#0 " in data: + found = log_file + if any(x in data for x in prioritize_tokens): + # this is the likely cause of the crash + break + if found is None: + # UBSan error (non-ASan builds) + if ": runtime error: " in data: + found = log_file + # catch all (choose the one with info for now) + elif data: + fallback = log_file + return found or fallback + + @staticmethod + def _find_valgrind(logs: list[Path]) -> Path | None: + """Search through log files for a Valgrind log. Empty files are ignored. + + Args: + logs: List of log files to search. + + Returns: + Log file if a match is found otherwise None. + """ + for log_file in logs: + if "valgrind" in log_file.name and log_file.stat().st_size: + return log_file + return None class Report: + """A crash report.""" + DEFAULT_MAJOR = "NO_STACK" DEFAULT_MINOR = "NO_STACK" HANG_STACK_HEIGHT = 10 @@ -65,8 +228,9 @@ def __init__( unstable: bool = False, ) -> None: self._crash_info: CrashInfo | None = None - self._logs = self._select_logs(log_path) - assert self._logs is not None + self._logs = LogMap.create(log_path) + # if both stderr and stdout are missing something is wrong + assert self._logs.stderr or self._logs.stdout self._short_signature: str | None = None self._signature = None self._target_binary = target_binary @@ -101,7 +265,7 @@ def calc_hash(signature: CrashSignature | None) -> str: """Create unique hash from a signature. Args: - signature: + signature: Crash signature object or None. Returns: Hash of the raw signature. @@ -148,8 +312,6 @@ def crash_info(self) -> CrashInfo: CrashInfo based on log data. """ if self._crash_info is None: - assert self._logs is not None - assert self.path is not None # create ProgramConfiguration that can be reported to a FM server if Path(f"{self._target_binary}.fuzzmanagerconf").is_file(): # attempt to use ".fuzzmanagerconf" @@ -230,119 +392,6 @@ def crash_signature_max_frames( break return suggested_frames + ignore - @staticmethod - def _find_ffpuppet_worker(logs: list[Path]) -> Path | None: - """Search through list of log files for a ffpuppet worker log. - - Args: - logs: List of log files to search. - - Returns: - Log file if a match is found otherwise None. - """ - found = None - for log_file in (x for x in logs if "ffp_worker" in x.name): - if found is not None: - # we only expect one log here... - LOG.warning("overwriting previously selected '%s'", log_file) - found = log_file - return found - - @staticmethod - def _find_minidump(logs: list[Path]) -> Path | None: - """Search through list of log files for a minidump log. - - Args: - logs: List of log files to search. - - Returns: - Log file if a match is found otherwise None. - """ - re_dump_req = re_compile( - r"\d+\|0\|.+?\|google_breakpad::ExceptionHandler::WriteMinidump" - ) - for log_file in (x for x in logs if "minidump" in x.name): - with log_file.open() as log_fp: - data = log_fp.read(65536) - # this will select log that contains "Crash|SIGSEGV|" or - # the desired "DUMP_REQUESTED" log - # TODO: review this it may be too strict - # see mozilla-central/source/accessible/ipc/DocAccessibleParent.cpp#452 - if "Crash|DUMP_REQUESTED|" not in data or re_dump_req.search(data): - return log_file - return None - - @staticmethod - def _find_sanitizer(logs: list[Path]) -> Path | None: - """Search through list of log files for a sanitizer (ASan, UBSan, etc...) log. - - Args: - logs: List of log files to search. - - Returns: - Log file if a match is found otherwise None. - """ - # pattern to identify the ASan crash triggered when the parent process goes away - # TODO: this may no longer be required - re_e10s_forced = re_compile( - r""" - ==\d+==ERROR:.+?SEGV\son.+?0x[0]+\s\(.+?T2\).+? - #0\s+0x[0-9a-f]+\sin\s+mozilla::ipc::MessageChannel::OnChannelErrorFromLink - """, - DOTALL | VERBOSE, - ) - # this is a list of Sanitizer error reports to prioritize - # Sanitizer reports not included below are deprioritized - prioritize_tokens = ( - "use-after-", - "-buffer-overflow on", - ": data race ", - ": SEGV on ", - "access-violation on ", - "attempting free on ", - "negative-size-param", - "-param-overlap", - ) - fallback = None - found = None - for log_file in (x for x in logs if "asan" in x.name): - with log_file.open() as log_fp: - data = log_fp.read(65536) - # look for interesting crash info in the log - if "==ERROR:" in data or "WARNING:" in data: - # check for e10s forced crash - if re_e10s_forced.search(data) is not None: - continue - # make sure there is something that looks like a stack frame - if "#0 " in data: - found = log_file - if any(x in data for x in prioritize_tokens): - # this is the likely cause of the crash - break - if found is None: - # UBSan error (non-ASan builds) - if ": runtime error: " in data: - found = log_file - # catch all (choose the one with info for now) - elif data: - fallback = log_file - return found or fallback - - @staticmethod - def _find_valgrind(logs: list[Path]) -> Path | None: - """Search through log files for a Valgrind log. Empty files are ignored. - - Args: - logs: List of log files to search. - - Returns: - Log file if a match is found otherwise None. - """ - for log_file in logs: - if "valgrind" in log_file.name and log_file.stat().st_size: - return log_file - return None - @staticmethod def _load_log(path: Path) -> list[str]: """Load and sanitize text from a file for use with CrashInfo.fromRawCrashData(). @@ -393,45 +442,8 @@ def preferred(self) -> Path | None: Returns: Log file. """ - assert self._logs is not None return self._logs.aux or self._logs.stderr - @classmethod - def _select_logs(cls, path: Path) -> LogMap | None: - """Scan path for file containing stderr, stdout and other (aux) - data and build a LogMap. - - Args: - path: Location to scan for log files. - - Returns: - A LogMap pointing to log files or None if path is empty. - """ - files = (x for x in path.iterdir() if x.is_file()) - # order by date hopefully the oldest log is the cause of the issue - to_scan = sorted(files, key=lambda x: x.stat().st_mtime) - if not to_scan: - LOG.warning("No files found in '%s'", path) - return None - # look for file to use as aux log - log_aux = cls._find_sanitizer(to_scan) - if log_aux is None: - log_aux = cls._find_valgrind(to_scan) - if log_aux is None: - log_aux = cls._find_minidump(to_scan) - if log_aux is None: - log_aux = cls._find_ffpuppet_worker(to_scan) - # look for stderr and stdout log files - log_err = None - log_out = None - for log_files in to_scan: - if "stderr" in log_files.name: - log_err = log_files - elif "stdout" in log_files.name: - log_out = log_files - result = LogMap(log_aux, log_err, log_out) - return result if any(result) else None - @property def short_signature(self) -> str: """Short signature of the report created by FuzzManager. @@ -476,6 +488,6 @@ def tail(in_file: Path, size_limit: int) -> None: out_fd, out_file = mkstemp(prefix="taillog_", dir=grz_tmp()) with open(out_fd, "wb") as out_fp: out_fp.write(b"[LOG TAILED]\n") - copyfileobj(in_fp, out_fp, 0x10000) # 64KB chunks + copyfileobj(in_fp, out_fp, 65536) in_file.unlink() move(out_file, in_file) diff --git a/src/grizzly/common/test_report.py b/src/grizzly/common/test_report.py index cbb296e7..bd00a9cb 100644 --- a/src/grizzly/common/test_report.py +++ b/src/grizzly/common/test_report.py @@ -9,7 +9,7 @@ from FTB.Signatures.CrashInfo import CrashInfo, TraceParsingError from pytest import mark, raises -from .report import Report +from .report import LogMap, Report def _create_crash_log(log_path): @@ -76,181 +76,6 @@ def test_report_03(tmp_path): def test_report_04(tmp_path): - """test Report._select_logs() uninteresting data""" - # test with empty path - assert Report._select_logs(tmp_path) is None - # empty file - (tmp_path / "not_a_log.txt").touch() - assert Report._select_logs(tmp_path) is None - - -def test_report_05(tmp_path): - """test Report._select_logs()""" - # small log with nothing interesting - with (tmp_path / "log_asan.txt.1").open("wb") as log_fp: - log_fp.write(b"SHORT LOG\n") - log_fp.write(b"filler line") - # crash on another thread - with (tmp_path / "log_asan.txt.2").open("wb") as log_fp: - log_fp.write(b"GOOD LOG\n") - log_fp.write( - b"==70811==ERROR: AddressSanitizer: SEGV on unknown address 0x00000BADF00D" - ) - log_fp.write( - b" (pc 0x7f4c0bb54c67 bp 0x7f4c07bea380 sp 0x7f4c07bea360 T0)\n" - ) # must be 2nd line - # pad out to 6 lines - for l_no in range(4): - log_fp.write(b" #%d blah...\n" % l_no) - # child log that should be ignored (created when parent crashes) - with (tmp_path / "log_asan.txt.3").open("wb") as log_fp: - log_fp.write(b"BAD LOG\n") - log_fp.write( - b"==70811==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000000" - ) - log_fp.write( - b" (pc 0x7f4c0bb54c67 bp 0x7f4c07bea380 sp 0x7f4c07bea360 T2)\n" - ) # must be 2nd line - # pad out to 6 lines - for l_no in range(4): - log_fp.write(b" #%d blah...\n" % l_no) - (tmp_path / "log_mindump_blah.txt").write_bytes(b"minidump log") - (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log") - (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log") - # should be ignored in favor of "GOOD LOG" - (tmp_path / "log_ffp_worker_blah.txt").write_bytes(b"worker log") - log_map = Report._select_logs(tmp_path) - assert log_map - assert "GOOD LOG" in log_map.aux.read_text() - assert "STDERR" in log_map.stderr.read_text() - assert "STDOUT" in log_map.stdout.read_text() - - -def test_report_06(tmp_path): - """test minidump with Report._select_logs()""" - (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log") - (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log") - with (tmp_path / "log_minidump_01.txt").open("wb") as log_fp: - log_fp.write(b"GPU|||\n") - log_fp.write(b"Crash|SIGSEGV|0x0|0\n") - log_fp.write(b"minidump log\n") - (tmp_path / "log_ffp_worker_blah.txt").write_bytes(b"worker log") - log_map = Report._select_logs(tmp_path) - assert log_map - assert log_map.stderr.is_file() - assert log_map.stdout.is_file() - assert "minidump log" in log_map.aux.read_text() - - -def test_report_07(tmp_path): - """test selecting preferred DUMP_REQUESTED minidump with Report._select_logs()""" - (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log") - (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log") - with (tmp_path / "log_minidump_01.txt").open("wb") as log_fp: - log_fp.write(b"GPU|||\n") - log_fp.write(b"Crash|DUMP_REQUESTED|0x7f9518665d18|0\n") - log_fp.write(b"0|0|bar.so|sadf|a.cc:739484451a63|3066|0x0\n") - log_fp.write(b"0|1|gar.so|fdsa|b.cc:739484451a63|1644|0x12\n") - with (tmp_path / "log_minidump_02.txt").open("wb") as log_fp: - log_fp.write(b"GPU|||\n") - log_fp.write(b"Crash|DUMP_REQUESTED|0x7f57ac9e2e14|0\n") - log_fp.write( - b"0|0|foo.so|google_breakpad::ExceptionHandler::WriteMinidump|" - b"bar.cc:234|674|0xc\n" - ) - log_fp.write( - b"0|1|foo.so|google_breakpad::ExceptionHandler::WriteMinidump|" - b"bar.cc:4a2|645|0x8\n" - ) - with (tmp_path / "log_minidump_03.txt").open("wb") as log_fp: - log_fp.write(b"GPU|||\n") - log_fp.write(b"Crash|DUMP_REQUESTED|0x7f9518665d18|0\n") - log_fp.write(b"0|0|bar.so|sadf|a.cc:1234|3066|0x0\n") - log_fp.write(b"0|1|gar.so|fdsa|b.cc:4323|1644|0x12\n") - log_map = Report._select_logs(tmp_path) - assert log_map - assert log_map.stderr.is_file() - assert log_map.stdout.is_file() - assert "google_breakpad::ExceptionHandler::WriteMinidump" in log_map.aux.read_text() - - -def test_report_08(tmp_path): - """test selecting worker logs with Report._select_logs()""" - (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log") - (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log") - (tmp_path / "log_ffp_worker_1.txt").write_bytes(b"worker log") - # we should only ever see one but if we see multiple we warn, so test that. - (tmp_path / "log_ffp_worker_2.txt").write_bytes(b"worker log") - log_map = Report._select_logs(tmp_path) - assert log_map - assert log_map.stderr.is_file() - assert log_map.stdout.is_file() - assert "worker log" in log_map.aux.read_text() - - -def test_report_09(tmp_path): - """test prioritizing sanitizer logs with Report._find_sanitizer()""" - # NOTE: ordered by selection priority in order to use previously added logs - # test empty - (tmp_path / "log_asan.txt.0").touch() - assert Report._find_sanitizer(list(tmp_path.iterdir())) is None - # test *San log with data - (tmp_path / "log_asan.txt.1").write_text("test") - selected = Report._find_sanitizer(list(tmp_path.iterdir())) - assert selected is not None - assert "test" in selected.read_text() - # test UBSan log - (tmp_path / "log_asan.txt.1").write_text( - "test.cc:3:5: runtime error: signed integer overflow: ..." - ) - selected = Report._find_sanitizer(list(tmp_path.iterdir())) - assert selected is not None - assert "runtime error: signed integer overflow" in selected.read_text() - # test selecting ASan report - with (tmp_path / "log_asan.txt.2").open("wb") as log_fp: - # missing stack - log_fp.write(b"==1184==ERROR: AddressSanitizer: BUS on ... blah\n") - with (tmp_path / "log_asan.txt.3").open("wb") as log_fp: - log_fp.write(b"==9482==ERROR: AddressSanitizer: stack-overflow on ...\n") - for l_no in range(4): - log_fp.write(b" #%d blah...\n" % (l_no,)) - selected = Report._find_sanitizer(list(tmp_path.iterdir())) - assert selected is not None - assert "AddressSanitizer: stack-overflow" in selected.read_text() - # test selecting prioritized - with (tmp_path / "log_asan.txt.4").open("wb") as log_fp: - log_fp.write( - b"==1942==ERROR: AddressSanitizer: heap-use-after-free on ... blah\n" - ) - for l_no in range(4): - log_fp.write(b" #%d blah...\n" % (l_no,)) - with (tmp_path / "log_asan.txt.5").open("wb") as log_fp: - log_fp.write(b"==1984==ERROR: AddressSanitizer: SEGV on ... blah\n") - log_fp.write(b"missing trace...\n") - with (tmp_path / "log_asan.txt.6").open("wb") as log_fp: - log_fp.write(b"ERROR: Failed to mmap\n") - selected = Report._find_sanitizer(list(tmp_path.iterdir())) - assert selected is not None - assert "heap-use-after-free" in selected.read_text() - # test selecting TSan reports - tsan_path = tmp_path / "tsan" - tsan_path.mkdir() - (tsan_path / "log_asan_benign.txt").write_text( - "==27531==WARNING: Symbolizer buffer too small\n" - "==27531==WARNING: Symbolizer buffer too small" - ) - tsan_report = tsan_path / "log_asan_report.txt" - tsan_report.write_text( - "WARNING: ThreadSanitizer: data race (pid=26919)\n" - " Write of size 8 at 0x7f0ca2fc3400 by thread T51:\n" - " #0 memcpy /sanitizer_common_interceptors.inc:810:5 (lib+0x6656e)\n" - ) - selected = Report._find_sanitizer(list(tsan_path.iterdir())) - assert selected is not None - assert selected == tsan_report - - -def test_report_10(tmp_path): """test Report() size_limit""" (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log\n" * 200) (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log\n" * 200) @@ -273,19 +98,7 @@ def test_report_10(tmp_path): assert not tmp_path.is_dir() -def test_report_11(tmp_path): - """test selecting Valgrind logs with Report._select_logs()""" - (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log") - (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log") - (tmp_path / "log_valgrind.txt").write_bytes(b"valgrind log") - log_map = Report._select_logs(tmp_path) - assert log_map - assert log_map.stderr.is_file() - assert log_map.stdout.is_file() - assert "valgrind log" in log_map.aux.read_text() - - -def test_report_12(tmp_path): +def test_report_05(tmp_path): """test Report.crash_info""" (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log") (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log") @@ -310,7 +123,7 @@ def test_report_12(tmp_path): assert report._crash_info.configuration.product == "grizzly-test" -def test_report_13(mocker, tmp_path): +def test_report_06(mocker, tmp_path): """test Report.crash_info with unparsable log""" crash_info = mocker.patch("grizzly.common.report.CrashInfo", autospec=True) crash_info.fromRawCrashData.side_effect = TraceParsingError(line_no=0) @@ -333,7 +146,7 @@ def test_report_13(mocker, tmp_path): (None, False), ], ) -def test_report_14(mocker, tmp_path, sig_cache, has_sig): +def test_report_07(mocker, tmp_path, sig_cache, has_sig): """test Report.crash_signature and Report.crash_hash""" mocker.patch("grizzly.common.report.ProgramConfiguration", autospec=True) collector = mocker.patch("grizzly.common.report.Collector", autospec=True) @@ -377,7 +190,7 @@ def test_report_14(mocker, tmp_path, sig_cache, has_sig): (("1", "2", "3", "4", "5", "std::panicking::rust_panic"), 5), ], ) -def test_report_15(mocker, backtrace, lines): +def test_report_08(mocker, backtrace, lines): """test Report.crash_signature_max_frames()""" info = mocker.Mock(spec=CrashInfo, backtrace=backtrace) assert Report.crash_signature_max_frames(info, suggested_frames=5) == lines @@ -396,7 +209,7 @@ def test_report_15(mocker, backtrace, lines): ("a\n\0", 2), ], ) -def test_report_16(tmp_path, data, lines): +def test_report_09(tmp_path, data, lines): """test Report._load_log()""" log = tmp_path / "test-log.txt" log.write_text(data) @@ -414,7 +227,7 @@ def test_report_16(tmp_path, data, lines): (True, True, "Potential hang detected"), ], ) -def test_report_17(mocker, tmp_path, hang, has_log, expected): +def test_report_10(mocker, tmp_path, hang, has_log, expected): """test Report.short_signature""" mocker.patch("grizzly.common.report.ProgramConfiguration", autospec=True) collector = mocker.patch("grizzly.common.report.Collector", autospec=True) @@ -428,3 +241,182 @@ def test_report_17(mocker, tmp_path, hang, has_log, expected): assert report.short_signature == expected if hang: assert report.crash_hash == "hang" + + +def test_log_map_01(tmp_path): + """test LogMap.create()""" + # small log with nothing interesting + with (tmp_path / "log_asan.txt.1").open("wb") as log_fp: + log_fp.write(b"SHORT LOG\n") + log_fp.write(b"filler line") + # crash on another thread + with (tmp_path / "log_asan.txt.2").open("wb") as log_fp: + log_fp.write(b"GOOD LOG\n") + log_fp.write( + b"==70811==ERROR: AddressSanitizer: SEGV on unknown address 0x00000BADF00D" + ) + log_fp.write( + b" (pc 0x7f4c0bb54c67 bp 0x7f4c07bea380 sp 0x7f4c07bea360 T0)\n" + ) # must be 2nd line + # pad out to 6 lines + for l_no in range(4): + log_fp.write(b" #%d blah...\n" % l_no) + # child log that should be ignored (created when parent crashes) + with (tmp_path / "log_asan.txt.3").open("wb") as log_fp: + log_fp.write(b"BAD LOG\n") + log_fp.write( + b"==70811==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000000" + ) + log_fp.write( + b" (pc 0x7f4c0bb54c67 bp 0x7f4c07bea380 sp 0x7f4c07bea360 T2)\n" + ) # must be 2nd line + # pad out to 6 lines + for l_no in range(4): + log_fp.write(b" #%d blah...\n" % l_no) + (tmp_path / "log_mindump_blah.txt").write_bytes(b"minidump log") + (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log") + (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log") + # should be ignored in favor of "GOOD LOG" + (tmp_path / "log_ffp_worker_blah.txt").write_bytes(b"worker log") + log_map = LogMap.create(tmp_path) + assert all(log_map) + assert "GOOD LOG" in log_map.aux.read_text() + assert "STDERR" in log_map.stderr.read_text() + assert "STDOUT" in log_map.stdout.read_text() + + +def test_log_map_02(tmp_path): + """test minidump with LogMap.create()""" + (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log") + (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log") + with (tmp_path / "log_minidump_01.txt").open("wb") as log_fp: + log_fp.write(b"GPU|||\n") + log_fp.write(b"Crash|SIGSEGV|0x0|0\n") + log_fp.write(b"minidump log\n") + (tmp_path / "log_ffp_worker_blah.txt").write_bytes(b"worker log") + log_map = LogMap.create(tmp_path) + assert log_map.stderr.is_file() + assert log_map.stdout.is_file() + assert "minidump log" in log_map.aux.read_text() + + +def test_log_map_03(tmp_path): + """test selecting preferred DUMP_REQUESTED minidump with LogMap.create()""" + (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log") + (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log") + with (tmp_path / "log_minidump_01.txt").open("wb") as log_fp: + log_fp.write(b"GPU|||\n") + log_fp.write(b"Crash|DUMP_REQUESTED|0x7f9518665d18|0\n") + log_fp.write(b"0|0|bar.so|sadf|a.cc:739484451a63|3066|0x0\n") + log_fp.write(b"0|1|gar.so|fdsa|b.cc:739484451a63|1644|0x12\n") + with (tmp_path / "log_minidump_02.txt").open("wb") as log_fp: + log_fp.write(b"GPU|||\n") + log_fp.write(b"Crash|DUMP_REQUESTED|0x7f57ac9e2e14|0\n") + log_fp.write( + b"0|0|foo.so|google_breakpad::ExceptionHandler::WriteMinidump|" + b"bar.cc:234|674|0xc\n" + ) + log_fp.write( + b"0|1|foo.so|google_breakpad::ExceptionHandler::WriteMinidump|" + b"bar.cc:4a2|645|0x8\n" + ) + with (tmp_path / "log_minidump_03.txt").open("wb") as log_fp: + log_fp.write(b"GPU|||\n") + log_fp.write(b"Crash|DUMP_REQUESTED|0x7f9518665d18|0\n") + log_fp.write(b"0|0|bar.so|sadf|a.cc:1234|3066|0x0\n") + log_fp.write(b"0|1|gar.so|fdsa|b.cc:4323|1644|0x12\n") + log_map = LogMap.create(tmp_path) + assert log_map.stderr.is_file() + assert log_map.stdout.is_file() + assert "google_breakpad::ExceptionHandler::WriteMinidump" in log_map.aux.read_text() + + +def test_log_map_04(tmp_path): + """test selecting worker logs with LogMap.create()""" + (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log") + (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log") + (tmp_path / "log_ffp_worker_1.txt").write_bytes(b"worker log") + # we should only ever see one but if we see multiple we warn, so test that. + (tmp_path / "log_ffp_worker_2.txt").write_bytes(b"worker log") + log_map = LogMap.create(tmp_path) + assert log_map.stderr.is_file() + assert log_map.stdout.is_file() + assert "worker log" in log_map.aux.read_text() + + +def test_log_map_05(tmp_path): + """test prioritizing sanitizer logs with LogMap._find_sanitizer()""" + # NOTE: ordered by selection priority in order to use previously added logs + # test empty + (tmp_path / "log_asan.txt.0").touch() + assert LogMap._find_sanitizer(list(tmp_path.iterdir())) is None + + # test *San log with data + (tmp_path / "log_asan.txt.1").write_text("test") + selected = LogMap._find_sanitizer(list(tmp_path.iterdir())) + assert selected is not None + assert "test" in selected.read_text() + # test UBSan log + (tmp_path / "log_asan.txt.1").write_text( + "test.cc:3:5: runtime error: signed integer overflow: ..." + ) + selected = LogMap._find_sanitizer(list(tmp_path.iterdir())) + assert selected is not None + assert "runtime error: signed integer overflow" in selected.read_text() + + # test selecting ASan report + with (tmp_path / "log_asan.txt.2").open("wb") as log_fp: + # missing stack + log_fp.write(b"==1184==ERROR: AddressSanitizer: BUS on ... blah\n") + with (tmp_path / "log_asan.txt.3").open("wb") as log_fp: + log_fp.write(b"==9482==ERROR: AddressSanitizer: stack-overflow on ...\n") + for l_no in range(4): + log_fp.write(b" #%d blah...\n" % (l_no,)) + selected = LogMap._find_sanitizer(list(tmp_path.iterdir())) + assert selected is not None + assert "AddressSanitizer: stack-overflow" in selected.read_text() + + # test selecting prioritized + with (tmp_path / "log_asan.txt.4").open("wb") as log_fp: + log_fp.write( + b"==1942==ERROR: AddressSanitizer: heap-use-after-free on ... blah\n" + ) + for l_no in range(4): + log_fp.write(b" #%d blah...\n" % (l_no,)) + with (tmp_path / "log_asan.txt.5").open("wb") as log_fp: + log_fp.write(b"==1984==ERROR: AddressSanitizer: SEGV on ... blah\n") + log_fp.write(b"missing trace...\n") + with (tmp_path / "log_asan.txt.6").open("wb") as log_fp: + log_fp.write(b"ERROR: Failed to mmap\n") + selected = LogMap._find_sanitizer(list(tmp_path.iterdir())) + assert selected is not None + assert "heap-use-after-free" in selected.read_text() + + # test selecting TSan reports + tsan_path = tmp_path / "tsan" + tsan_path.mkdir() + (tsan_path / "log_asan_benign.txt").write_text( + "==27531==WARNING: Symbolizer buffer too small\n" + "==27531==WARNING: Symbolizer buffer too small" + ) + tsan_report = tsan_path / "log_asan_report.txt" + tsan_report.write_text( + "WARNING: ThreadSanitizer: data race (pid=26919)\n" + " Write of size 8 at 0x7f0ca2fc3400 by thread T51:\n" + " #0 memcpy /sanitizer_common_interceptors.inc:810:5 (lib+0x6656e)\n" + ) + selected = LogMap._find_sanitizer(list(tsan_path.iterdir())) + assert selected is not None + assert selected == tsan_report + + +def test_log_map_06(tmp_path): + """test selecting Valgrind logs with LogMap.create()""" + (tmp_path / "log_stderr.txt").write_bytes(b"STDERR log") + (tmp_path / "log_stdout.txt").write_bytes(b"STDOUT log") + (tmp_path / "log_valgrind.txt").write_bytes(b"valgrind log") + log_map = LogMap.create(tmp_path) + assert log_map + assert log_map.stderr.is_file() + assert log_map.stdout.is_file() + assert "valgrind log" in log_map.aux.read_text() From 4a175656b5af0bf305637504c4651e3044ecf66f Mon Sep 17 00:00:00 2001 From: Tyson Smith Date: Wed, 25 Mar 2026 16:56:07 -0700 Subject: [PATCH 5/5] fix(replay): use Target.create_report() --- src/grizzly/replay/conftest.py | 29 ++++--- src/grizzly/replay/replay.py | 17 ++-- src/grizzly/replay/test_main.py | 22 +++-- src/grizzly/replay/test_replay.py | 129 ++++++++++++++++-------------- 4 files changed, 101 insertions(+), 96 deletions(-) diff --git a/src/grizzly/replay/conftest.py b/src/grizzly/replay/conftest.py index e621e88e..4062e6c8 100644 --- a/src/grizzly/replay/conftest.py +++ b/src/grizzly/replay/conftest.py @@ -3,12 +3,15 @@ # file, You can obtain one at http://mozilla.org/MPL/2.0/. """Common unit test fixtures for `grizzly.replay`.""" +from itertools import count from pathlib import Path from pytest import fixture from sapphire import Sapphire +from ..common.report import Report + @fixture def server(mocker): @@ -20,12 +23,20 @@ def server(mocker): @fixture -def tmp_path_grz_tmp(tmp_path, mocker): - """Provide an alternate working directory for testing.""" - - def _grz_tmp(*subdir): - path = Path(tmp_path, "grizzly", *subdir) - path.mkdir(parents=True, exist_ok=True) - return path - - mocker.patch("grizzly.replay.replay.grz_tmp", _grz_tmp) +def fake_create_report(tmp_path): + """Factory fixture that creates Reports from fake log data in tmp_path.""" + _counter = count() + + def _create(is_hang=False, unstable=False): + log_path = tmp_path / f"logs_{next(_counter)}" + log_path.mkdir() + (log_path / "log_stderr.txt").write_text("STDERR log\n") + (log_path / "log_stdout.txt").write_text("STDOUT log\n") + with (log_path / "log_asan_blah.txt").open("w") as log_fp: + log_fp.write("==1==ERROR: AddressSanitizer: ") + log_fp.write("SEGV on unknown address 0x0 (pc 0x0 bp 0x0 sp 0x0 T0)\n") + log_fp.write(" #0 0xbad000 in foo /file1.c:123:234\n") + log_fp.write(" #1 0x1337dd in bar /file2.c:1806:19\n") + return Report(log_path, Path("bin"), is_hang=is_hang, unstable=unstable) + + return _create diff --git a/src/grizzly/replay/replay.py b/src/grizzly/replay/replay.py index a2fd48a9..b32b4ab6 100644 --- a/src/grizzly/replay/replay.py +++ b/src/grizzly/replay/replay.py @@ -5,8 +5,6 @@ from dataclasses import dataclass from logging import getLogger -from pathlib import Path -from tempfile import mkdtemp from typing import TYPE_CHECKING, cast from sapphire import ServerMap @@ -16,11 +14,12 @@ from ..common.reporter import FilesystemReporter, FuzzManagerReporter from ..common.runner import Runner, RunResult from ..common.status import SimpleStatus -from ..common.utils import HARNESS_FILE, grz_tmp +from ..common.utils import HARNESS_FILE from ..target import Result, Target if TYPE_CHECKING: from collections.abc import Callable, Iterable + from pathlib import Path from FTB.Signatures.CrashInfo import CrashSignature @@ -279,7 +278,8 @@ def _process_reports( x.count >= min_results for x in reports.values() if x.expected ) results: list[ReplayResult] = [] - for crash_hash, result in reports.items(): + while reports: + crash_hash, result = reports.popitem() # if min_results not met (success=False) cleanup expected reports if not success and result.expected: if not self._any_crash: @@ -301,8 +301,6 @@ def _process_reports( and not any(x.expected for x in results) ): LOG.info("Perhaps try with --relaunch=1") - # active reports have been moved to results clear reports collection - reports.clear() return results def run( @@ -444,12 +442,7 @@ def run( # processing the result may take a few minutes (rr) # update console to show progress LOG.info("Processing result...") - # TODO: use self.target.create_report here - log_path = Path(mkdtemp(prefix="logs_", dir=grz_tmp("logs"))) - self.target.save_logs(log_path) - report = Report( - log_path, - self.target.binary, + report = self.target.create_report( is_hang=run_result.timeout, unstable=runner.startup_failure, ) diff --git a/src/grizzly/replay/test_main.py b/src/grizzly/replay/test_main.py index b4f65248..9fe0dd67 100644 --- a/src/grizzly/replay/test_main.py +++ b/src/grizzly/replay/test_main.py @@ -20,15 +20,11 @@ TargetLaunchTimeout, ) from .main import main -from .test_replay import _fake_save_logs -pytestmark = mark.usefixtures( - "patch_collector", - "tmp_path_grz_tmp", -) +pytestmark = mark.usefixtures("patch_collector") -def test_main_01(mocker, server, tmp_path): +def test_main_01(mocker, server, tmp_path, fake_create_report): """test main()""" # This is a typical scenario - a test that reproduces results ~50% of the time. # Of the four attempts only the first and third will 'reproduce' the result @@ -46,7 +42,7 @@ def test_main_01(mocker, server, tmp_path): target.asset_mgr = mocker.Mock(spec_set=AssetManager) target.check_result.side_effect = (Result.FOUND, Result.NONE, Result.FOUND) target.filtered_environ.return_value = {"ENV": "123"} - target.save_logs = _fake_save_logs + target.create_report.side_effect = fake_create_report load_target.return_value.return_value = target with TestCase("test.html", "adpt") as src: src.env_vars["TEST_VAR"] = "100" @@ -110,7 +106,7 @@ def test_main_01(mocker, server, tmp_path): (Result.FOUND, Result.NONE), ], ) -def test_main_02(mocker, server, tmp_path, repro_results): +def test_main_02(mocker, server, tmp_path, fake_create_report, repro_results): """test main() - no repro""" mocker.patch("grizzly.common.runner.sleep", autospec=True) server.serve_path.return_value = ServeResult( @@ -122,7 +118,7 @@ def test_main_02(mocker, server, tmp_path, repro_results): ) target.check_result.side_effect = repro_results target.filtered_environ.return_value = {} - target.save_logs = _fake_save_logs + target.create_report.side_effect = fake_create_report mocker.patch( "grizzly.replay.main.load_plugin", autospec=True, @@ -276,7 +272,7 @@ def test_main_04(mocker, tmp_path): assert reporter.return_value.submit.call_count == 0 -def test_main_05(mocker, server, tmp_path): +def test_main_05(mocker, server, tmp_path, fake_create_report): """test main() loading specified assets""" server.serve_path.return_value = ServeResult({}, Served.NONE, False) # setup Target @@ -286,7 +282,7 @@ def test_main_05(mocker, server, tmp_path): target.check_result.return_value = Result.FOUND target.filtered_environ.return_value = {} target.monitor.is_healthy.return_value = False - target.save_logs = _fake_save_logs + target.create_report.side_effect = fake_create_report mocker.patch( "grizzly.replay.main.load_plugin", autospec=True, @@ -408,7 +404,7 @@ def test_main_06( assert load_target.return_value.call_args[-1]["valgrind"] == valgrind -def test_main_07(mocker, server, tmp_path): +def test_main_07(mocker, server, tmp_path, fake_create_report): """test main() - report to FuzzManager""" mocker.patch("grizzly.common.runner.sleep", autospec=True) server.serve_path.return_value = ServeResult({}, Served.NONE, False) @@ -419,7 +415,7 @@ def test_main_07(mocker, server, tmp_path): spec_set=Target, binary=Path("bin"), environ={}, launch_timeout=30 ) target.check_result.side_effect = (Result.FOUND,) - target.save_logs = _fake_save_logs + target.create_report.side_effect = fake_create_report load_target.return_value.return_value = target with TestCase("test.html", "adpt") as src: src.add_from_bytes(b"test", src.entry_point) diff --git a/src/grizzly/replay/test_replay.py b/src/grizzly/replay/test_replay.py index ffdfe6ba..723a0f82 100644 --- a/src/grizzly/replay/test_replay.py +++ b/src/grizzly/replay/test_replay.py @@ -6,6 +6,7 @@ from itertools import cycle from logging import INFO from pathlib import Path +from tempfile import mkdtemp from FTB.Signatures.CrashInfo import CrashSignature from pytest import mark, raises @@ -17,19 +18,7 @@ from ..target import Result, Target from .replay import ReplayManager, ReplayResult -pytestmark = mark.usefixtures("patch_collector", "tmp_path_grz_tmp") - - -def _fake_save_logs(result_logs): - """write fake log data to disk""" - log_path = Path(result_logs) - (log_path / "log_stderr.txt").write_text("STDERR log\n") - (log_path / "log_stdout.txt").write_text("STDOUT log\n") - with (log_path / "log_asan_blah.txt").open("w") as log_fp: - log_fp.write("==1==ERROR: AddressSanitizer: ") - log_fp.write("SEGV on unknown address 0x0 (pc 0x0 bp 0x0 sp 0x0 T0)\n") - log_fp.write(" #0 0xbad000 in foo /file1.c:123:234\n") - log_fp.write(" #1 0x1337dd in bar /file2.c:1806:19\n") +pytestmark = mark.usefixtures("patch_collector") @mark.parametrize("post_launch_delay", [0, -1]) @@ -116,22 +105,25 @@ def test_replay_03(mocker, server, tmp_path): @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): +def test_replay_04( + mocker, server, tmp_path, fake_create_report, 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 sig_parsed: - target.save_logs = _fake_save_logs + target.create_report.side_effect = fake_create_report else: - def _save_logs(result_logs): - """create uninteresting logs""" - log_path = Path(result_logs) + def _create_report_no_stack(is_hang=False, unstable=False): + """create a Report with uninteresting logs (no stack)""" + log_path = Path(mkdtemp(prefix="logs_", dir=tmp_path)) (log_path / "log_stderr.txt").write_text("STDERR log\n") (log_path / "log_stdout.txt").write_text("STDOUT log\n") + return Report(log_path, Path("bin"), is_hang=is_hang, unstable=unstable) - target.save_logs = _save_logs + target.create_report.side_effect = _create_report_no_stack (tmp_path / "a.html").touch() server.serve_path.return_value = ServeResult( {"a.html": tmp_path / "a.html"}, Served.ALL, False @@ -179,14 +171,14 @@ def test_replay_05(mocker, server): target.reset_mock() -def test_replay_06(mocker, server): +def test_replay_06(mocker, server, fake_create_report): """test ReplayManager.run() delayed failure - following test entry point not requested""" target = mocker.Mock(spec_set=Target, binary=Path("bin"), launch_timeout=30) type(target).closed = mocker.PropertyMock(side_effect=(True, False, True)) target.check_result.side_effect = (Result.NONE, Result.FOUND) target.monitor.is_healthy.return_value = False - target.save_logs = _fake_save_logs + target.create_report.side_effect = fake_create_report tests = [mocker.MagicMock(spec_set=TestCase, entry_point="a.html")] server.serve_path.side_effect = ( ServeResult({"a.html": "/fake/path"}, Served.ALL, False), @@ -220,14 +212,14 @@ def test_replay_07(mocker, server): assert target.handle_hang.call_count == 1 -def test_replay_08(mocker, server): +def test_replay_08(mocker, server, fake_create_report): """test ReplayManager.run() - early exit""" mocker.patch("grizzly.common.runner.sleep", autospec=True) server.serve_path.return_value = ServeResult( {"a.html": "/fake/path"}, Served.ALL, False ) target = mocker.Mock(spec_set=Target, binary=Path("bin"), launch_timeout=30) - target.save_logs = _fake_save_logs + target.create_report.side_effect = fake_create_report tests = [mocker.MagicMock(spec_set=TestCase, entry_point="a.html")] # early failure target.check_result.side_effect = ( @@ -294,16 +286,15 @@ def test_replay_09(mocker, server): report_1 = mocker.Mock(spec_set=Report, crash_hash="h1", major="0123", minor="0123") report_2 = mocker.Mock(spec_set=Report, crash_hash="h2", major="0123", minor="abcd") report_3 = mocker.Mock(spec_set=Report, crash_hash="h2", major="0123", minor="abcd") - fake_report = mocker.patch("grizzly.replay.replay.Report", autospec=True) - fake_report.side_effect = (report_1, report_2, report_3) - fake_report.calc_hash.return_value = "bucketHASH" server.serve_path.return_value = ServeResult( {"a.html": "/fake/path"}, Served.ALL, False ) signature = mocker.Mock() signature.matches.side_effect = (True, False, False) + signature.rawSignature = "raw_sig" target = mocker.Mock(spec_set=Target, launch_timeout=30) target.check_result.return_value = Result.FOUND + target.create_report.side_effect = (report_1, report_2, report_3) tests = [mocker.MagicMock(spec_set=TestCase, entry_point="a.html")] with ReplayManager( [], server, target, signature=signature, use_harness=False @@ -315,7 +306,7 @@ def test_replay_09(mocker, server): assert replay.status.iteration == 3 assert replay.status.results.total == 1 assert replay.status.ignored == 2 - assert fake_report.call_count == 3 + assert target.create_report.call_count == 3 assert len(results) == 1 assert not results[0].expected assert results[0].count == 2 @@ -329,16 +320,15 @@ def test_replay_10(mocker, server): """test ReplayManager.run() - test signatures - multiple matches""" report_0 = mocker.Mock(spec_set=Report, crash_hash="h1", major="0123", minor="0123") report_1 = mocker.Mock(spec_set=Report, crash_hash="h2", major="0123", minor="abcd") - fake_report = mocker.patch("grizzly.replay.replay.Report", autospec=True) - fake_report.side_effect = (report_0, report_1) - fake_report.calc_hash.return_value = "bucketHASH" server.serve_path.return_value = ServeResult( {"a.html": "/fake/path"}, Served.ALL, False ) - sig = mocker.Mock(spec_set=CrashSignature) + sig = mocker.Mock() sig.matches.side_effect = (True, True) + sig.rawSignature = "raw_sig" target = mocker.Mock(spec_set=Target, launch_timeout=30) target.check_result.return_value = Result.FOUND + target.create_report.side_effect = (report_0, report_1) target.monitor.is_healthy.return_value = False tests = [mocker.MagicMock(spec_set=TestCase, entry_point="a.html")] with ReplayManager([], server, target, signature=sig, use_harness=False) as replay: @@ -349,7 +339,7 @@ def test_replay_10(mocker, server): assert replay.status.iteration == 2 assert replay.status.results.total == 2 assert replay.status.ignored == 0 - assert fake_report.call_count == 2 + assert target.create_report.call_count == 2 assert len(results) == 1 assert results[0].expected assert results[0].count == 2 @@ -362,13 +352,12 @@ def test_replay_11(mocker, server): """test ReplayManager.run() - any crash - success""" report_1 = mocker.Mock(spec_set=Report, crash_hash="h1", major="0123", minor="0123") report_2 = mocker.Mock(spec_set=Report, crash_hash="h2", major="0123", minor="abcd") - fake_report = mocker.patch("grizzly.replay.replay.Report", autospec=True) - fake_report.side_effect = (report_1, report_2) server.serve_path.return_value = ServeResult( {"a.html": "/fake/path"}, Served.ALL, False ) target = mocker.Mock(spec_set=Target, launch_timeout=30) target.check_result.return_value = Result.FOUND + target.create_report.side_effect = (report_1, report_2) 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: @@ -379,7 +368,7 @@ def test_replay_11(mocker, server): assert replay.status.iteration == 2 assert replay.status.results.total == 2 assert replay.status.ignored == 0 - assert fake_report.call_count == 2 + assert target.create_report.call_count == 2 assert len(results) == 2 assert all(x.expected for x in results) assert sum(x.count for x in results if x.expected) == 2 @@ -391,8 +380,6 @@ def test_replay_12(mocker, server): """test ReplayManager.run() - any crash - fail to meet minimum""" report_1 = mocker.Mock(spec_set=Report, crash_hash="h1", major="0123", minor="0123") report_2 = mocker.Mock(spec_set=Report, crash_hash="h2", major="0123", minor="abcd") - fake_report = mocker.patch("grizzly.replay.replay.Report", autospec=True) - fake_report.side_effect = (report_1, report_2) server.serve_path.return_value = ServeResult( {"a.html": "/fake/path"}, Served.ALL, False ) @@ -403,6 +390,7 @@ def test_replay_12(mocker, server): Result.FOUND, Result.NONE, ) + target.create_report.side_effect = (report_1, report_2) target.monitor.is_healthy.return_value = False tests = [mocker.MagicMock(spec_set=TestCase, entry_point="a.html")] with ReplayManager([], server, target, any_crash=True) as replay: @@ -413,7 +401,7 @@ def test_replay_12(mocker, server): assert replay.status.iteration == 4 assert replay.status.results.total == 2 assert replay.status.ignored == 0 - assert fake_report.call_count == 2 + assert target.create_report.call_count == 2 assert report_1.cleanup.call_count == 1 assert report_2.cleanup.call_count == 1 @@ -500,7 +488,16 @@ def test_replay_12(mocker, server): ((ServeResult({}, Served.NONE, True),), None, 0, 0), ], ) -def test_replay_13(mocker, server, tmp_path, to_serve, sig_value, expected, unexpected): +def test_replay_13( + mocker, + server, + tmp_path, + fake_create_report, + to_serve, + sig_value, + expected, + unexpected, +): """test ReplayManager.run() - result after launch, before running test""" server.serve_path.side_effect = to_serve @@ -524,7 +521,7 @@ def test_replay_13(mocker, server, tmp_path, to_serve, sig_value, expected, unex 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.create_report.side_effect = fake_create_report target.monitor.is_healthy.return_value = False tests = [mocker.MagicMock(spec_set=TestCase, entry_point="a.html")] with ReplayManager(set(), server, target, any_crash=False, signature=sig) as replay: @@ -538,8 +535,9 @@ def test_replay_13(mocker, server, tmp_path, to_serve, sig_value, expected, unex def test_replay_14(mocker, server): """test ReplayManager.run() - no signature - use first crash""" - auto_sig = mocker.Mock(spec_set=CrashSignature) + auto_sig = mocker.Mock() auto_sig.matches.side_effect = (True, False, True) + auto_sig.rawSignature = "raw_sig" # original report_1 = mocker.Mock(spec_set=Report, crash_hash="h1", major="012", minor="999") report_1.crash_signature = auto_sig @@ -547,14 +545,12 @@ def test_replay_14(mocker, server): report_2 = mocker.Mock(spec_set=Report, crash_hash="h2", major="abc", minor="987") # matching report report_3 = mocker.Mock(spec_set=Report, crash_hash="h1", major="012", minor="999") - fake_report = mocker.patch("grizzly.replay.replay.Report", autospec=True) - fake_report.side_effect = (report_1, report_2, report_3) - fake_report.calc_hash.return_value = "bucket_hash" server.serve_path.return_value = ServeResult( {"a.html": "/fake/path"}, Served.ALL, False ) target = mocker.Mock(spec_set=Target, launch_timeout=30) target.check_result.return_value = Result.FOUND + target.create_report.side_effect = (report_1, report_2, report_3) target.monitor.is_healthy.return_value = False tests = [mocker.MagicMock(spec_set=TestCase, entry_point="a.html")] with ReplayManager([], server, target, use_harness=False) as replay: @@ -565,7 +561,7 @@ def test_replay_14(mocker, server): assert replay.status.iteration == 3 assert replay.status.results.total == 2 assert replay.status.ignored == 1 - assert fake_report.call_count == 3 + assert target.create_report.call_count == 3 assert len(results) == 2 assert sum(x.expected for x in results) == 1 assert sum(x.count for x in results if x.expected) == 2 @@ -577,14 +573,13 @@ def test_replay_14(mocker, server): def test_replay_15(mocker, server): """test ReplayManager.run() - unexpected exception""" report_0 = mocker.Mock(spec_set=Report, crash_hash="h1", major="0123", minor="0123") - fake_report = mocker.patch("grizzly.replay.replay.Report", autospec=True) - fake_report.side_effect = (report_0,) server.serve_path.side_effect = ( ServeResult({"a.html": "/fake/path"}, Served.ALL, False), KeyboardInterrupt, ) target = mocker.Mock(spec_set=Target, launch_timeout=30) target.check_result.return_value = Result.FOUND + target.create_report.side_effect = (report_0,) tests = [mocker.MagicMock(spec_set=TestCase, entry_point="a.html")] with ReplayManager( [], server, target, any_crash=True, use_harness=True, relaunch=2 @@ -598,7 +593,7 @@ def test_replay_15(mocker, server): assert replay.status.ignored == 0 assert target.close.call_count == 1 assert target.monitor.is_healthy.call_count == 0 - assert fake_report.call_count == 1 + assert target.create_report.call_count == 1 assert report_0.cleanup.call_count == 1 @@ -647,7 +642,7 @@ def test_replay_17(mocker, server): assert target.monitor.is_healthy.call_count == 5 -def test_replay_18(mocker, server): +def test_replay_18(mocker, server, fake_create_report): """test ReplayManager.run() - multiple TestCases - successful repro""" server.serve_path.side_effect = ( ServeResult({"0.html": "/fake/path"}, Served.ALL, False), @@ -661,7 +656,7 @@ def test_replay_18(mocker, server): Result.FOUND, ) target.monitor.is_healthy.return_value = False - target.save_logs = _fake_save_logs + target.create_report.side_effect = fake_create_report tests = [ mocker.MagicMock(spec_set=TestCase, entry_point=f"{i}.html") for i in range(3) ] @@ -769,7 +764,15 @@ def test_replay_20(mocker, tmp_path): ], ) def test_replay_23( - mocker, server, expect_hang, is_hang, use_sig, match_sig, ignored, results + mocker, + server, + fake_create_report, + expect_hang, + is_hang, + use_sig, + match_sig, + ignored, + results, ): """test ReplayManager.run() - detect hangs""" server.serve_path.return_value = ServeResult( @@ -784,7 +787,7 @@ def test_replay_23( target = mocker.Mock(spec_set=Target, binary=Path("bin"), launch_timeout=30) target.check_result.return_value = Result.FOUND target.handle_hang.return_value = False - target.save_logs = _fake_save_logs + target.create_report.side_effect = fake_create_report 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: @@ -847,11 +850,11 @@ def test_replay_25(mocker, server, tmp_path): call_count = 0 - def _save_logs_variation(result_logs): - """create different stacks each call""" + def _create_report_variation(is_hang=False, unstable=False): + """create Reports with different stacks each call""" nonlocal call_count call_count += 1 - log_path = Path(result_logs) + log_path = Path(mkdtemp(prefix="logs_", dir=tmp_path)) (log_path / "log_stderr.txt").write_text("STDERR log\n") (log_path / "log_stdout.txt").write_text("STDOUT log\n") with (log_path / "log_asan_blah.txt").open("w") as log_fp: @@ -859,8 +862,9 @@ def _save_logs_variation(result_logs): log_fp.write("SEGV on unknown address 0x0 (pc 0x0 bp 0x0 sp 0x0 T0)\n") log_fp.write(f" #0 0xbad000 in call_a{call_count:02d} file.c:23:34\n") log_fp.write(f" #1 0xbad001 in call_b{call_count:02d} file.c:12:45\n") + return Report(log_path, Path("bin"), is_hang=is_hang, unstable=unstable) - target.save_logs.side_effect = _save_logs_variation + target.create_report.side_effect = _create_report_variation (tmp_path / "a.html").touch() server.serve_path.return_value = ServeResult( @@ -913,11 +917,11 @@ def test_replay_26(mocker, server, tmp_path, stderr_log, ignored, total, include target.check_result.return_value = Result.FOUND target.monitor.is_healthy.return_value = False - def _save_logs_variation(result_logs): - """create logs""" + def _create_report_variation(is_hang=False, unstable=False): + """create Reports with varying logs""" nonlocal stderr_log nonlocal include_stack - log_path = Path(result_logs) + log_path = Path(mkdtemp(prefix="logs_", dir=tmp_path)) (log_path / "log_stderr.txt").write_text(stderr_log.pop(0)) (log_path / "log_stdout.txt").write_text("STDOUT log\n") if include_stack.pop(0): @@ -926,8 +930,9 @@ def _save_logs_variation(result_logs): log_fp.write("SEGV on unknown address 0x0 (pc 0x0 bp 0x0 sp 0x0 T0)\n") log_fp.write(" #0 0xbad000 in call_a file.c:23:34\n") log_fp.write(" #1 0xbad001 in call_b file.c:12:45\n") + return Report(log_path, Path("bin"), is_hang=is_hang, unstable=unstable) - target.save_logs.side_effect = _save_logs_variation + target.create_report.side_effect = _create_report_variation has_sig = include_stack[0] (tmp_path / "a.html").touch() @@ -950,12 +955,12 @@ def _save_logs_variation(result_logs): assert results -def test_replay_27(mocker, server, tmp_path): +def test_replay_27(mocker, server, tmp_path, fake_create_report): """test ReplayManager.run() - collect served files""" target = mocker.Mock(spec_set=Target, binary=Path("bin"), launch_timeout=30) target.check_result.side_effect = (Result.FOUND,) target.monitor.is_healthy.return_value = False - target.save_logs = _fake_save_logs + target.create_report.side_effect = fake_create_report src = tmp_path / "src" with TestCase("test.html", "test-adapter") as test: test.add_from_bytes(b"", test.entry_point)