diff --git a/.github/scripts/run_case_optimization.sh b/.github/scripts/run_case_optimization.sh index 75ab3a44a..0a6bd1b44 100755 --- a/.github/scripts/run_case_optimization.sh +++ b/.github/scripts/run_case_optimization.sh @@ -102,6 +102,23 @@ for case in "${benchmarks[@]}"; do # its run is sharded across concurrent jobs sharing one workspace, so a # fallback rebuild would race on the shared install paths (the collision the # --no-build guard above prevents). + # The same offload diagnostics the test harness sets. These cases run on + # GPUs, and a memory fault here previously surfaced as a bare device + # address with nothing to act on. Both variables are inert until a fault; + # the debug agent is what gives CCE a faulting kernel at all, and is set + # only where its library is actually reachable. + # OFFLOAD_TRACK_ALLOCATION_TRACES / _NUM_KERNEL_LAUNCH_TRACES are deliberately + # NOT set: measured on an MI210 with amdflang, either one alone turns a + # 5.94 s test into a >400 s timeout, because they instrument every + # allocation and every kernel launch. See toolchain/mfc/gpu_diagnostics.py. + # Skipped when the caller already chose a tool, or is collecting a GPU core + # dump -- the agent is mutually exclusive with one, so loading it anyway + # would leave them with no dump and no reason why. + if [ -z "${HSA_TOOLS_LIB:-}" ] && [ -z "${HSA_ENABLE_DEBUG:-}" ] \ + && [ -n "${ROCM_PATH:-}" ] && [ -f "$ROCM_PATH/lib/librocm-debug-agent.so.2" ]; then + export HSA_TOOLS_LIB=librocm-debug-agent.so.2 + fi + run_log="$(mktemp)" ./mfc.sh run "$case" --case-optimization $gpu_opts $build_opts -n "$ngpus" -j 8 -c "$job_cluster" -- --gbpp 1 --steps 10 2>&1 | tee "$run_log" run_rc=${PIPESTATUS[0]} @@ -118,6 +135,14 @@ for case in "${benchmarks[@]}"; do else run_ok=0 fi + + # A fault's agent report runs to tens of thousands of lines and the useful + # part is in the middle, so re-print a bounded summary at the end where a + # reader will actually find it. Silent when the log has no agent report. + if [ "$run_ok" = 0 ]; then + build/venv/bin/python3 .github/scripts/summarize_gpu_fault.py "$run_log" || true + fi + rm -f "$run_log" if [ "$run_ok" = 1 ]; then diff --git a/.github/scripts/summarize_gpu_fault.py b/.github/scripts/summarize_gpu_fault.py new file mode 100755 index 000000000..c8aee9949 --- /dev/null +++ b/.github/scripts/summarize_gpu_fault.py @@ -0,0 +1,42 @@ +#!/usr/bin/env python3 +"""Print a bounded summary of a GPU memory fault in a run log. + +For callers that are shell scripts. The ROCm debug agent emits tens of +thousands of lines per fault -- one disassembly and register dump repeated per +faulting wave -- and the part worth reading (the faulting kernel, the fault +reason, the stop-PC distribution) is buried in the middle, so `tail` cannot +find it. + +Exits 0 having printed a summary, or 1 having printed nothing when the log has +no agent report, which lets the caller fall back to whatever it did before. +""" + +import os +import sys + +sys.path.insert(0, os.path.join(os.path.dirname(__file__), "..", "..", "toolchain")) + +from mfc.gpu_diagnostics import summarize_rocm_debug_agent # noqa: E402 + + +def main() -> int: + if len(sys.argv) != 2: + print(f"usage: {sys.argv[0]} ", file=sys.stderr) + return 2 + + try: + with open(sys.argv[1], "r", encoding="utf-8", errors="replace") as log: + summary = summarize_rocm_debug_agent(log.read()) + except OSError as exc: + print(f"could not read {sys.argv[1]}: {exc}", file=sys.stderr) + return 1 + + if not summary: + return 1 + + print(summary) + return 0 + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/src/simulation/m_time_steppers.fpp b/src/simulation/m_time_steppers.fpp index 9a04225b0..6f77aea5a 100644 --- a/src/simulation/m_time_steppers.fpp +++ b/src/simulation/m_time_steppers.fpp @@ -492,6 +492,30 @@ contains q_cons_ts(stor)%vf(i)%sf(j, k, l) = q_cons_ts(1)%vf(i)%sf(j, k, l) end if if (igr) then + ! ############ DO NOT MERGE ############ + ! Deliberate out-of-bounds device write, to make + ! CI produce a real GPU memory fault so the retry + ! diagnostics can be seen end to end in a job log. + ! Scoped to igr so only a handful of tests fault + ! instead of the whole GPU matrix. + ! Revert with: git revert + ! GPU builds only: GPU_PARALLEL_LOOP emits nothing + ! on CPU, so without this gate the same statement + ! is an out-of-bounds *host* write -- undefined + ! behaviour, and not the clean device fault this + ! is meant to produce. +#ifdef MFC_GPU + ! 2e9 elements (16 GB) past the base. Measured + ! on an MI210: 1e8 (762 MB) does NOT fault once + ! several GB of device arrays exist -- it lands + ! inside a neighbouring allocation and silently + ! corrupts, which is what the first attempt did. + ! 1e11 overshoots into + ! HSA_STATUS_ERROR_MEMORY_APERTURE_VIOLATION, a + ! different error the detector does not match. + q_cons_ts(1)%vf(i)%sf(j + 2000000000, k, l) = 1._wp +#endif + ! ###################################### q_cons_ts(1)%vf(i)%sf(j, k, l) = (rk_coef(s, 1)*q_cons_ts(1)%vf(i)%sf(j, k, l) + rk_coef(s, & & 2)*q_cons_ts(stor)%vf(i)%sf(j, k, l) + rk_coef(s, 3)*rhs_vf(i)%sf(j, k, & & l))/rk_coef(s, 4) diff --git a/toolchain/mfc/bench.py b/toolchain/mfc/bench.py index 68146d5aa..daf3cb501 100644 --- a/toolchain/mfc/bench.py +++ b/toolchain/mfc/bench.py @@ -12,6 +12,7 @@ from .build import DEFAULT_TARGETS, SIMULATION, get_targets from .common import MFC_BENCH_FILEPATH, MFC_BUILD_DIR, MFCException, console_safe, create_directory, file_dump_yaml, file_load_yaml, format_list_to_string, log_tail, system +from .gpu_diagnostics import fault_diagnostic_env, summarize_rocm_debug_agent from .printer import cons from .state import ARG, CFG @@ -23,6 +24,25 @@ class BenchCase: args: typing.List[str] +def bench_failure_report(log_filepath: str) -> str: + """What to show for a failed benchmark case. + + A GPU memory fault under the ROCm debug agent runs to tens of thousands of + lines, nearly all of it one disassembly and register dump repeated per wave. + A fixed tail is not merely long here, it is wrong: measured on a real + report, the last 80 lines are a single wave's registers and the kernel name + -- the only part worth having -- is not among them. Fall back to the tail + only when there is no agent report to summarize. + """ + try: + with open(log_filepath, "r", encoding="utf-8", errors="replace") as log_file: + summary = summarize_rocm_debug_agent(log_file.read()) + except OSError: + return log_tail(log_filepath) + + return summary or log_tail(log_filepath) + + def bench(targets=None): if targets is None: targets = ARG("targets") @@ -76,6 +96,10 @@ def bench(targets=None): ["./mfc.sh", "run", case.path] + ["--targets"] + [t.name for t in targets] + ["--output-summary", summary_filepath] + case.args + ["--", "--gbpp", str(ARG("mem"))], stdout=log_file, stderr=subprocess.STDOUT, + # Same offload diagnostics the test harness uses: + # these cases run on GPUs too, and a fault here + # was previously reported as a bare address. + env=fault_diagnostic_env(dict(os.environ)), ) # Check return code (handle CompletedProcess or int defensively) @@ -89,7 +113,7 @@ def bench(targets=None): cons.print(f"[bold red]ERROR[/bold red]: Case {case.slug} failed with exit code {rc}") # Print the log, not just its path: this file lives # on the cluster and no artifact upload collects it. - cons.print(console_safe(log_tail(log_filepath))) + cons.print(console_safe(bench_failure_report(log_filepath))) failed_cases.append(case.slug) break @@ -101,7 +125,7 @@ def bench(targets=None): time.sleep(5) continue cons.print(f"[bold red]ERROR[/bold red]: Summary file not created for {case.slug}") - cons.print(console_safe(log_tail(log_filepath))) + cons.print(console_safe(bench_failure_report(log_filepath))) cons.print(f"[bold red] Expected: {summary_filepath}[/bold red]") failed_cases.append(case.slug) break diff --git a/toolchain/mfc/gpu_diagnostics.py b/toolchain/mfc/gpu_diagnostics.py new file mode 100644 index 000000000..ecfdb0124 --- /dev/null +++ b/toolchain/mfc/gpu_diagnostics.py @@ -0,0 +1,200 @@ +"""Offload-runtime diagnostics for GPU memory faults. + +Shared by the test harness, the benchmark runner and the case-optimization CI +script -- all three run GPU cases and all three need the same answer when one +faults. Kept out of test/ because bench.py depending on the test module to +explain a crash would be the wrong way round. +""" + +import collections +import os +import re +import typing + +# The marker _handle_case attaches to the exception it raises, so that +# classify_error can tell a GPU memory fault from any other execution failure. +# Two constraints, both learned the hard way: +# +# * It must be one of the signatures below verbatim, because classify_error +# recognises it by running the same matcher over the message. An earlier +# version wrote "[gpu-memory-fault]" while the reader searched for "memory +# access fault by gpu", so the two never matched and the feature was dead +# while seven source-inspecting tests passed. +# * No square brackets. main.py renders these messages through Rich, which +# parses "[...]" as a style tag and deletes it -- which is why a CI log +# showed a bare "Failed to execute MFC. " with the marker missing. +GPU_FAULT_MARKER = "(memory access fault by GPU)" + +GPU_FAULT_SIGNATURES = ( + # AMD/HSA -- Frontier, both CCE and AFAR builds. + "memory access fault by gpu", + "offload error: memory access fault", + # NVHPC -- Phoenix. Worded nothing like the AMD ones, so matching only the + # above meant 189 faults on a Phoenix gpu-acc shard were never recognised. + # Only the specific error: NVHPC prefixes unrelated failures with + # "Accelerator Fatal Error" too, including "call to cuMemAlloc returned + # error 2: Out of memory", which is not a memory fault and must not be + # classified as one. + "cuda_error_illegal_address", +) + + +def is_gpu_memory_fault(text: str) -> bool: + """Whether output shows a GPU memory fault, as opposed to any other failure. + + Deliberately narrow. PMIX_ERR_NO_PERMISSIONS and friends appear in 16% of + *passing* self-hosted jobs, so anything broader would fire constantly. + """ + lowered = (text or "").lower() + + return any(sig in lowered for sig in GPU_FAULT_SIGNATURES) + + +def fault_diagnostic_env(base: dict) -> dict: + """`base` plus the one diagnostic cheap enough to leave on. + + Set on every run rather than on a retry: the ROCm debug agent writes nothing + until the runtime is already aborting on a memory fault, so a first failure + is explained without spending a second run to reproduce it. + + Two variables that used to live here were removed after measurement -- see + below. What is left is the agent, which is what names the faulting kernel. + """ + env = dict(base) + + # OFFLOAD_TRACK_ALLOCATION_TRACES and OFFLOAD_TRACK_NUM_KERNEL_LAUNCH_TRACES + # were set here and had to be removed. They instrument every allocation and + # every kernel launch, so a healthy run pays continuously: on an MI210 with + # amdflang, test AFBCBDFA takes 5.94 s with neither and times out past 400 s + # with either one alone -- enough, against the 1-hour test timeout, to turn + # a fault into a timeout and hide what they exist to explain. + # + # They looked free only because the A/B that cleared them ran on CCE, whose + # offload runtime ignores libomptarget variables entirely. What they added, + # one line on whether the address was ever a real allocation, the agent's + # kernel name and source line subsume. + + # Skipped when the caller is already debugging by hand: they chose a tool, + # or they set HSA_ENABLE_DEBUG to collect a GPU core dump, which the agent + # is mutually exclusive with. Loading it anyway would leave them with + # "Failed to enable debug interface" and no dump. An attached rocgdb trips + # the same path. + # + # Cost, Frontier CCE --gpu mp over four interleaved pairs: no effect + # detected on a healthy run (resolution ~0.8%), no output at all until + # something faults, and +0.387 s on a faulting run -- 0.011% of the test + # timeout. ~3-4% on an MI210 (n=2). It does not supersede libomptarget's own + # report on the AFAR lane; it is exclusive with ROCr core dumps only. + if "HSA_TOOLS_LIB" not in env and not env.get("HSA_ENABLE_DEBUG") and rocm_debug_agent_path() is not None: + env["HSA_TOOLS_LIB"] = ROCM_DEBUG_AGENT + + return env + + +ROCM_DEBUG_AGENT = "librocm-debug-agent.so.2" + + +def rocm_debug_agent_path() -> typing.Optional[str]: + """Where the ROCm debug agent lives, or None if it is not reachable. + + MUST be evaluated at call time, never cached at import. On Frontier the + library is on disk the whole time, but /opt/rocm-*/lib only reaches + LD_LIBRARY_PATH once `mfc.sh load` runs. A gate evaluated at import decides + "absent" on the one machine this exists for, and does it indistinguishably + from the Phoenix case where the library really is missing. + + Probes for the file rather than dlopen'ing it: ctypes.CDLL would load a + debug agent into the test harness's own process to answer a question about + the subprocess. + """ + rocm_path = os.environ.get("ROCM_PATH", "") + search = [os.path.join(rocm_path, "lib")] if rocm_path else [] + search += os.environ.get("LD_LIBRARY_PATH", "").split(os.pathsep) + + for directory in search: + if directory and os.path.isfile(os.path.join(directory, ROCM_DEBUG_AGENT)): + return os.path.join(directory, ROCM_DEBUG_AGENT) + + return None + + +def summarize_rocm_debug_agent(out: str, max_disasm: int = 14) -> str: + """Collapse librocm-debug-agent output to a bounded, informative summary. + + The agent repeats an identical disassembly block and a 115-line register + dump per faulting wave -- 125 waves produced 14,635 lines on a 49x39 case. + Only the kernel name, fault reason, stop-PC distribution and one + representative wave carry information; the rest is duplicated. + + A fixed tail cannot substitute. Measured on that log: the first 80 lines are + one wave's registers and the last 80 are another's, and the kernel name -- + the entire point -- appears in neither. The stop-PC histogram is kept + because the waves halted at four distinct PCs whose modal one is a load + while the injected fault is a write, so quoting a single PC without the + distribution hands the reader the wrong instruction. + + Returns '' when there is no agent report, so callers fall back to the raw + output. + + The format is NOT stable across ROCm versions, and the failure is silent -- + no wave match means an empty summary and a fallback to tens of thousands of + raw lines, with nothing saying why. Measured between two versions: + + 6.3.1 wave_124: pc=0x7ff77e253408 (stopped, reason: MEMORY_VIOLATION) + 7.2.0 wave_250: pc=0x7ff734dcbf3c (kernel_code_entry=0x... <...>, + kernargs=0x...) (stopped, reason: MEMORY_VIOLATION) + + 6.3.1 Memory access fault by GPU node-4 (Agent handle: ...) on address + 7.2.0 OFFLOAD ERROR: memory access fault by GPU 4 (agent ...) at ... + + An earlier version required pc= and "(stopped, reason:" to be adjacent and + matched the fault line case-sensitively on "Memory". It returned nothing at + all for 65,210 lines of real 7.2.0 output. Hence the tolerant separator, and + reusing is_gpu_memory_fault rather than hardcoding one version's wording. + Both formats are pinned by fixtures below. + + Validated against three real reports, not one: + + CCE acc ROCm 6.3.1 14,635 lines -> 37 + CCE mp ROCm 6.3.1 13,826 lines -> 35 + AFAR mp ROCm 7.2.0 65,210 lines -> 36 + + and output from a run with no agent loaded still yields '', so the fallback + is intact. The stop-PC histogram earns its place most on the CCE OpenMP + lane, which halts at seven distinct PCs (62/21/19/10/10/2/1) against four + for CCE OpenACC and one for AFAR: quoting a single PC would be wrong there + six times in seven. + """ + waves = re.findall(r"^wave_\d+: pc=(0x[0-9a-f]+).*?\(stopped, reason: (\w+)\)", out, re.M) + if not waves: + return "" + + lines = out.splitlines() + fault = next((line for line in lines if is_gpu_memory_fault(line)), None) + kernels = sorted({m.group(1) for m in re.finditer(r"^Disassembly for function (.+):$", out, re.M)}) + pcs = collections.Counter(pc for pc, _ in waves) + reasons = collections.Counter(reason for _, reason in waves) + + summary = [f"=== GPU fault summary (rocm-debug-agent, {len(lines)} lines collapsed) ==="] + if fault: + summary.append(fault.strip()) + summary.append("faulting kernel(s): " + (", ".join(kernels) or "")) + summary.append(f"faulting waves: {len(waves)} [" + ", ".join(f"{r} x{n}" for r, n in reasons.most_common()) + "]") + summary.append("stop PCs: " + ", ".join(f"{pc} x{n}" for pc, n in pcs.most_common())) + summary.append("NOTE: waves halt on fault detection, so the PC is near -- not necessarily at -- the offending instruction.") + + disasm_starts = [n for n, line in enumerate(lines) if line.startswith("Disassembly for function")] + if disasm_starts: + start = disasm_starts[0] + end = next((n for n, line in enumerate(lines[start:], start) if line.startswith("End of disassembly")), start + max_disasm) + summary += ["", f"--- disassembly (1 of {len(disasm_starts)} identical blocks) ---"] + summary += lines[start : min(end + 1, start + max_disasm)] + + modal_pc = pcs.most_common(1)[0][0] + start = next((n for n, line in enumerate(lines) if re.match(r"^wave_\d+: pc=" + re.escape(modal_pc) + r"(?![0-9a-f])", line)), None) + if start is not None: + summary += ["", f"--- representative wave (modal PC {modal_pc}, {pcs[modal_pc]} of {len(waves)} waves) ---"] + summary += lines[start : start + max_disasm] + summary.append(f" ... (registers for {len(waves) - 1} further waves suppressed)") + + return "\n".join(summary) diff --git a/toolchain/mfc/test/case.py b/toolchain/mfc/test/case.py index 14dfc4ef9..0b8835250 100644 --- a/toolchain/mfc/test/case.py +++ b/toolchain/mfc/test/case.py @@ -172,7 +172,7 @@ def __init__( merge = {key: val for key, val in merge.items() if val is not None} super().__init__(merge) - def run(self, targets: List[Union[str, MFCTarget]], gpus: Set[int]) -> subprocess.CompletedProcess: + def run(self, targets: List[Union[str, MFCTarget]], gpus: Set[int], env: dict = None) -> subprocess.CompletedProcess: if gpus is not None and len(gpus) != 0: gpus_select = ["--gpus"] + [str(_) for _ in gpus] else: @@ -192,9 +192,11 @@ def run(self, targets: List[Union[str, MFCTarget]], gpus: Set[int]) -> subproces command = [mfc_script, "run", filepath, "--no-build", *tasks, *case_optimization, *jobs, "-t", *target_names, *gpus_select, *ARG("--")] - return common.system(command, print_cmd=False, text=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT) + # env is per-subprocess, never os.environ: cases run in worker threads, + # so a mutated global would leak into every concurrent case. + return common.system(command, print_cmd=False, text=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, env=env) - def run_restart(self, targets, gpus): + def run_restart(self, targets, gpus, env: dict = None): """Run a restart roundtrip: simulate to midpoint, then restart to end.""" # NOTE: This method overrides t_step_save to produce exactly one save # per phase (at the boundary step). Tests using restart_check=True @@ -213,7 +215,7 @@ def run_restart(self, targets, gpus): # Phase 1: Run to midpoint (generates restart data) self.params = {**orig, "t_step_stop": mid_step, "t_step_save": mid_step - orig["t_step_start"]} self.create_directory() - result1 = self.run(targets, gpus) + result1 = self.run(targets, gpus, env=env) if result1.returncode != 0: return result1 @@ -225,7 +227,7 @@ def run_restart(self, targets, gpus): # is run — it reads grid + IC directly from p_all/p0//. self.params = {**orig, "t_step_start": mid_step, "t_step_save": orig["t_step_stop"] - mid_step} self.create_directory() - result2 = self.run([SIMULATION], gpus) + result2 = self.run([SIMULATION], gpus, env=env) # Remove intermediate step files from D/ so only step 0 and # t_step_stop remain, matching the straight run's output. diff --git a/toolchain/mfc/test/test.py b/toolchain/mfc/test/test.py index 05720522d..127d76989 100644 --- a/toolchain/mfc/test/test.py +++ b/toolchain/mfc/test/test.py @@ -16,6 +16,13 @@ from .. import common, sched from ..build import HDF5, POST_PROCESS, PRE_PROCESS, SIMULATION, build from ..common import MFCException, console_safe, does_command_exist, format_list_to_string, get_program_output, log_tail +from ..gpu_diagnostics import ( + GPU_FAULT_MARKER, + fault_diagnostic_env, + is_gpu_memory_fault, + rocm_debug_agent_path, + summarize_rocm_debug_agent, +) from ..packer import packer from ..packer import tol as packtol from ..printer import cons @@ -620,7 +627,7 @@ def _handle_case(case: TestCase, devices: typing.Set[int]): # Check timeout before starting if timeout_flag.is_set(): raise TestTimeoutError("Test case exceeded 1 hour timeout") - cmd = case.run([PRE_PROCESS, SIMULATION], gpus=devices) + cmd = case.run([PRE_PROCESS, SIMULATION], gpus=devices, env=fault_diagnostic_env(dict(os.environ))) # Check timeout after simulation if timeout_flag.is_set(): @@ -631,7 +638,32 @@ def _handle_case(case: TestCase, devices: typing.Set[int]): common.file_write(out_filepath, cmd.stdout) if cmd.returncode != 0: - cons.print(cmd.stdout) + # The debug agent emits ~14k lines per fault, nearly all of it the + # same disassembly and register dump repeated per wave. Print the + # summary when there is one; the full capture is in out_pre_sim.txt. + agent_summary = summarize_rocm_debug_agent(cmd.stdout) + if agent_summary: + cons.print(console_safe(agent_summary)) + cons.print(f" full offload report: {out_filepath}") + else: + cons.print(cmd.stdout) + # Falling back is silent by nature: the raw output is printed + # and nothing says the summary was expected. That is exactly how + # a ROCm 6.3.1-only parser sat on the AFAR lane returning + # nothing for 65,210 lines of real 7.2.0 output. If the agent is + # reachable and this is a GPU fault, a missing summary means the + # agent did not load or its format moved again -- say so. + if is_gpu_memory_fault(cmd.stdout) and rocm_debug_agent_path() is not None: + cons.print( + " [yellow]warning[/yellow]: the ROCm debug agent is available and this is a GPU " + "memory fault, but no agent report was recognised. Either the agent did not load, or " + "its output format has changed and summarize_rocm_debug_agent needs updating." + ) + # Marked so classify_error buckets it as a GPU memory fault rather + # than a generic execution failure; the diagnostics that make it + # actionable are already in the output above. + if is_gpu_memory_fault(cmd.stdout): + raise MFCException(f"Test {case}: Failed to execute MFC {GPU_FAULT_MARKER}.") raise MFCException(f"Test {case}: Failed to execute MFC.") _assert_particle_cloud_ib_state(case) @@ -676,7 +708,7 @@ def _handle_case(case: TestCase, devices: typing.Set[int]): if timeout_flag.is_set(): raise TestTimeoutError("Test case exceeded 1 hour timeout") - restart_result = case.run_restart([PRE_PROCESS, SIMULATION], devices) + restart_result = case.run_restart([PRE_PROCESS, SIMULATION], devices, env=fault_diagnostic_env(dict(os.environ))) if timeout_flag.is_set(): raise TestTimeoutError("Test case exceeded 1 hour timeout") @@ -753,6 +785,10 @@ def classify_error(exc: Exception) -> str: return "timeout" if "nan" in text: return "NaN detected" + # Before the generic branch: a GPU fault's message also contains "failed to + # execute", and it is the one execution failure a retry provably cannot fix. + if is_gpu_memory_fault(text): + return "GPU memory fault" if "failed to execute" in text: return "execution failed" diff --git a/toolchain/mfc/test/test_gpu_fault_diagnostics.py b/toolchain/mfc/test/test_gpu_fault_diagnostics.py new file mode 100644 index 000000000..cd2a4d856 --- /dev/null +++ b/toolchain/mfc/test/test_gpu_fault_diagnostics.py @@ -0,0 +1,310 @@ +"""GPU memory faults should explain themselves the first time. + +A fault reaches CI as an address and, unaided, nothing else. Measured against a +deliberate out-of-bounds write at m_time_steppers.fpp:486, on all four GPU +lanes: NVHPC and AFAR name the faulting kernel for free, CCE names nothing and +no CRAY_ACC_* variable helps, and the ROCm debug agent names it everywhere it +is reachable -- at ROCr level, with no recompile. + +Nearly every failure in this area was silent, so these assert on content and on +the hand-offs between parts, never on presence alone. +""" + +import pathlib +import subprocess +import sys + +from mfc.gpu_diagnostics import ( + GPU_FAULT_MARKER, + ROCM_DEBUG_AGENT, + fault_diagnostic_env, + is_gpu_memory_fault, + rocm_debug_agent_path, + summarize_rocm_debug_agent, +) + +# Real agent output, verbatim, from two ROCm versions. The formats differ in +# ways that silently defeated a parser written against only one: 7.2.0 puts +# kernel_code_entry=/kernargs= between pc= and "(stopped, reason:", and words +# the fault line "OFFLOAD ERROR: memory access fault ... at virtual address". +ROCM_AGENT_FIXTURE_631 = """\ +Memory access fault by GPU node-4 (Agent handle: 0x3b24f40) on address 0x7ffb6a0f6000. Reason: Write access to a read-only page. +Disassembly for function s_tvd_rk$m_time_steppers_$ck_L486_6: + code object: file:///path/gpu-acc-c819d00b45/bin/simulation#offset=4657152&size=10843816 + loaded at: [0x7ff77da00000-0x7ff77feca9f9] + => 0x7ff77e253430 <+6192>: s_waitcnt vmcnt(0) lgkmcnt(0) + 0x7ff77e253434 <+6196>: v_sub_co_u32_e32 v5, vcc, v26, v42 +End of disassembly. +wave_0: pc=0x7ff77e253408 (stopped, reason: MEMORY_VIOLATION) + +scalar registers: + s0: d9800000 s1: 80007ffe +wave_1: pc=0x7ff77e253408 (stopped, reason: MEMORY_VIOLATION) + +scalar registers: + s0: d9800000 s1: 80007ffe +wave_2: pc=0x7ff77e2533fc (stopped, reason: MEMORY_VIOLATION) + +scalar registers: + s0: d9800000 s1: 80007ffe +""" + +ROCM_AGENT_FIXTURE_720 = """\ +OFFLOAD ERROR: memory access fault by GPU 4 (agent 0x55555896f810) at virtual address 0x7ffb61f02000. Reasons: Write access to a read-only page +Disassembly for function __omp_offloading_8116438_1c00689b__QMm_time_steppersPs_tvd_rk_l486: + code object: memory://415882#offset=0x7ff736b8c040&size=17250800 + loaded at: [0x7ff734000000-0x7ff736b0a4e8] + => 0x7ff734dcbf3c <+7484>: s_waitcnt vmcnt(0) lgkmcnt(0) + 0x7ff734dcbf40 <+7488>: v_mul_f64 v[12:13], v[52:53], v[16:17] +End of disassembly. +wave_249: pc=0x7ff734dcbf3c (kernel_code_entry=0x7ff736b8c040 <__omp_offloading_8116438_1c00689b__QMm_time_steppersPs_tvd_rk_l486>, kernargs=0x7ffb61f00000) (stopped, reason: MEMORY_VIOLATION) + +scalar registers: + s0: d9800000 s1: 80007ffe +wave_250: pc=0x7ff734dcbf3c (kernel_code_entry=0x7ff736b8c040 <__omp_offloading_8116438_1c00689b__QMm_time_steppersPs_tvd_rk_l486>, kernargs=0x7ffb61f00000) (stopped, reason: MEMORY_VIOLATION) + +scalar registers: + s0: d9800000 s1: 80007ffe +""" + + +# Detection. + + +def test_recognises_each_runtime_wording(): + # AMD/HSA (CCE), libomptarget (AFAR), and NVHPC, which words it nothing like + # the others -- matching only AMD's left 189 Phoenix faults unclassified. + assert is_gpu_memory_fault("Memory access fault by GPU node-9 on address 0x1") + assert is_gpu_memory_fault("OFFLOAD ERROR: memory access fault by GPU 4") + assert is_gpu_memory_fault("Accelerator Fatal Error: ... (CUDA_ERROR_ILLEGAL_ADDRESS)") + + +def test_does_not_fire_on_ordinary_failures(): + # PMIX noise appears in 16% of *passing* self-hosted jobs, and NVHPC uses + # "Accelerator Fatal Error" for out-of-memory too -- neither is a fault. + assert not is_gpu_memory_fault("Test x: Failed to execute MFC.") + assert not is_gpu_memory_fault("PMIX ERROR: PMIX_ERR_NO_PERMISSIONS in file dstore_base.c") + assert not is_gpu_memory_fault("Accelerator Fatal Error: call to cuMemAlloc returned error 2: Out of memory") + + +def test_the_marker_survives_the_hand_off_and_rich(): + """The failure site tags the exception; classify_error reads the tag back. + + The first version wrote "[gpu-memory-fault]" while the reader searched for + "memory access fault by gpu", so the two never matched and the feature was + dead while seven source-inspecting tests passed. Square brackets also make + Rich delete the marker as a style tag before it reaches the log. + """ + import io + + from rich.console import Console + + raised = f"Test x: Failed to execute MFC {GPU_FAULT_MARKER}." + assert is_gpu_memory_fault(raised) + + console = Console(file=io.StringIO(), force_terminal=False) + console.print(raised) + assert GPU_FAULT_MARKER in console.file.getvalue() + + +def test_a_gpu_fault_gets_its_own_failure_class(): + # Otherwise detecting it is inert: classify_error bucketed anything saying + # "failed to execute" as a generic execution failure. + from mfc.common import MFCException + from mfc.test.test import classify_error + + assert classify_error(MFCException(f"Test x: Failed to execute MFC {GPU_FAULT_MARKER}.")) == "GPU memory fault" + assert classify_error(MFCException("Test x: Failed to execute MFC.")) == "execution failed" + + +# What the run environment carries. + + +def test_only_the_agent_is_set(): + """Everything else was measured to be worse than nothing. + + CRAY_ACC_DEBUG named the wrong kernel in 81 of 102 traced faults, because + CCE dispatches async and its trace's tail is whatever ran next. + OFFLOAD_TRACK_ALLOCATION_TRACES and _NUM_KERNEL_LAUNCH_TRACES instrument + every allocation and every kernel launch: on an MI210 either one alone + turned a 5.94 s test into a >400 s timeout. + """ + env = fault_diagnostic_env({}) + + assert "CRAY_ACC_DEBUG" not in env + assert "OFFLOAD_TRACK_ALLOCATION_TRACES" not in env + assert "OFFLOAD_TRACK_NUM_KERNEL_LAUNCH_TRACES" not in env + + +def test_the_env_is_a_copy_and_keeps_what_it_was_given(): + # Cases run in worker threads; mutating a shared environment would leak + # settings into every concurrent case. + base = {"PATH": "/usr/bin", "HOME": "/home/x"} + env = fault_diagnostic_env(base) + + assert env["PATH"] == "/usr/bin" and env["HOME"] == "/home/x" + assert "HSA_TOOLS_LIB" not in base + + +def tmp_agent_dir() -> str: + """A directory laid out like a ROCm install, for the gate to find.""" + import os + import tempfile + + root = tempfile.mkdtemp() + os.makedirs(os.path.join(root, "lib"), exist_ok=True) + open(os.path.join(root, "lib", ROCM_DEBUG_AGENT), "w", encoding="utf-8").close() + return root + + +def test_the_agent_gate_re_reads_the_environment(monkeypatch): + """It must not be captured at import. + + On Frontier the library is on disk the whole time but only reaches + LD_LIBRARY_PATH once `mfc.sh load` runs, so an import-time gate reports + "absent" on the one machine this is for -- indistinguishably from Phoenix, + where it genuinely is missing. Pinned rather than trusting the host, which + may have a real ROCm install. + """ + import os + + monkeypatch.setenv("ROCM_PATH", "") + monkeypatch.setenv("LD_LIBRARY_PATH", "") + assert rocm_debug_agent_path() is None + assert "HSA_TOOLS_LIB" not in fault_diagnostic_env({}) + + monkeypatch.setenv("ROCM_PATH", tmp_agent_dir()) + assert rocm_debug_agent_path() is not None + assert fault_diagnostic_env({})["HSA_TOOLS_LIB"] == ROCM_DEBUG_AGENT + + monkeypatch.setenv("ROCM_PATH", "") + monkeypatch.setenv("LD_LIBRARY_PATH", os.path.join(tmp_agent_dir(), "lib")) + assert rocm_debug_agent_path() is not None + + +def test_a_developer_debugging_by_hand_is_left_alone(monkeypatch): + """`mfc.sh test` and `mfc.sh bench` are not only CI entry points. + + The agent is mutually exclusive with a ROCr core dump, so enabling it behind + someone collecting one gives them "Failed to enable debug interface" and no + dump, caused by the harness rather than anything they did. + """ + monkeypatch.setenv("ROCM_PATH", tmp_agent_dir()) + + assert "HSA_TOOLS_LIB" in fault_diagnostic_env({}) + assert "HSA_TOOLS_LIB" not in fault_diagnostic_env({"HSA_ENABLE_DEBUG": "1"}) + assert fault_diagnostic_env({"HSA_TOOLS_LIB": "libmine.so"})["HSA_TOOLS_LIB"] == "libmine.so" + + +# Collapsing the agent's output. + + +def test_both_rocm_formats_are_recognised(): + """A parser written against one version returns '' for the other. + + That happened: 65,210 lines of real 7.2.0 output produced nothing, on the + lane the summarizer exists to serve, with no error to explain it. Neither + format may be fixed at the other's expense. + """ + for name, fixture in (("6.3.1", ROCM_AGENT_FIXTURE_631), ("7.2.0", ROCM_AGENT_FIXTURE_720)): + summary = summarize_rocm_debug_agent(fixture) + assert summary, f"ROCm {name} agent output was not recognised" + assert "memory access fault" in summary.lower() + + +def test_the_summary_keeps_the_kernel_and_the_whole_pc_histogram(): + """The two things a fixed tail cannot give. + + On the real 14,635-line report the first 80 lines are one wave's registers + and the last 80 another's, so the kernel name is in neither. And the waves + stop at several PCs whose modal one is a load while the fault is a write -- + quoting one PC alone names the wrong instruction. + """ + summary = summarize_rocm_debug_agent(ROCM_AGENT_FIXTURE_720) + + assert "__omp_offloading_8116438_1c00689b__QMm_time_steppersPs_tvd_rk_l486" in summary + assert "0x7ff734dcbf3c x2" in summary + + for field in ("faulting kernel(s): ", "faulting waves: ", "stop PCs: ", "--- disassembly (1 of "): + assert field in summary, f"the summarizer no longer emits {field!r}" + + +def test_every_measured_symbol_form_survives(): + """Three manglings -- one per compiler, not one per offload model. + + CCE emits the same scheme for OpenACC and OpenMP offload, differing only in + a trailing counter, while AFAR's Flang form is different again. Reading any + two lanes suggests the offload model decides. + """ + for symbol in ( + "s_tvd_rk$m_time_steppers_$ck_L486_6", + "s_tvd_rk$m_time_steppers_$ck_L486_16", + "__omp_offloading_8116438_1c00689b__QMm_time_steppersPs_tvd_rk_l486", + ): + summary = summarize_rocm_debug_agent(ROCM_AGENT_FIXTURE_631.replace("s_tvd_rk$m_time_steppers_$ck_L486_6", symbol)) + assert symbol in summary and "486" in summary + + +def test_output_without_an_agent_report_falls_back(): + assert summarize_rocm_debug_agent("Memory access fault by GPU node-4 on address 0x1") == "" + assert summarize_rocm_debug_agent("") == "" + + +def test_a_missing_agent_report_on_a_gpu_fault_is_called_out(): + # The drift above is silent by nature -- raw output where a summary should + # be, and nothing saying why. If the agent is reachable and the failure IS a + # GPU fault, an unrecognised report has to say so. + import inspect + + from mfc.test.test import _handle_case + + src = inspect.getsource(_handle_case) + assert "rocm_debug_agent_path() is not None" in src + assert "format has changed" in src + + +# The other two callers. + + +def test_the_bench_runner_summarizes_rather_than_tailing(tmp_path): + """bench.py ran GPU cases with no fault handling at all. + + Padded past log_tail's 60-line window on purpose: with a short fixture the + tail contains the kernel name and this passes against the old behaviour. + """ + from mfc.bench import bench_failure_report + from mfc.common import log_tail + + log = tmp_path / "case.out" + log.write_text(ROCM_AGENT_FIXTURE_720 + "\n".join(f" v{n}: 0x0" for n in range(200)), encoding="utf-8") + assert "_QMm_time_steppersPs_tvd_rk_l486" not in log_tail(str(log)), "fixture too short to distinguish" + + assert "_QMm_time_steppersPs_tvd_rk_l486" in bench_failure_report(str(log)) + + plain = tmp_path / "plain.out" + plain.write_text("ordinary failure\nsomething went wrong\n", encoding="utf-8") + assert "something went wrong" in bench_failure_report(str(plain)) + + +def test_the_shell_summarizer_reports_absence_by_exit_code(tmp_path): + # The case-optimization script is shell, and needs to know when to fall back. + script = pathlib.Path(__file__).resolve().parents[3] / ".github" / "scripts" / "summarize_gpu_fault.py" + + agent = tmp_path / "agent.log" + agent.write_text(ROCM_AGENT_FIXTURE_720, encoding="utf-8") + found = subprocess.run([sys.executable, str(script), str(agent)], capture_output=True, text=True, check=False) + assert found.returncode == 0 and "_QMm_time_steppersPs_tvd_rk_l486" in found.stdout + + plain = tmp_path / "plain.log" + plain.write_text("ordinary failure\n", encoding="utf-8") + missing = subprocess.run([sys.executable, str(script), str(plain)], capture_output=True, text=True, check=False) + assert missing.returncode == 1 and missing.stdout.strip() == "" + + +def test_restart_cases_carry_the_diagnostics_too(): + # They reach the GPU through run_restart, which took no env at all. + import inspect + + from mfc.test.case import TestCase + + assert "env" in inspect.signature(TestCase.run_restart).parameters