diff --git a/projects/hrr/skills/decode-and-triage/SKILL.md b/projects/hrr/skills/decode-and-triage/SKILL.md index 7244693b8f55..1b8834aad446 100644 --- a/projects/hrr/skills/decode-and-triage/SKILL.md +++ b/projects/hrr/skills/decode-and-triage/SKILL.md @@ -172,12 +172,67 @@ native. Use `--no-replay` for metadata-only (no GPU). | `PASS` | Replay completed; D2H checks passed | | `MAF` | GPU memory access fault during replay | | `FAIL` | Replay finished but validation failed (e.g. D2H mismatch) | -| `ABORT` | Replay stopped early (fatal API, version mismatch, user abort) | +| `ABORT` | Replay stopped early (fatal API, version mismatch, queue abort, user abort, replay process killed by a signal) | +| `HANG` | Replay made no progress and the runner had to stop it (see `HRR_REPLAY_TIMEOUT`) | | `UNKNOWN` | Insufficient signal to classify (e.g. metadata-only triage, missing log) | When outcome is `UNKNOWN` or fault class is `unknown`, say so explicitly in the summary — do not invent a fault type. +A fault on the GPU and a crash of the replay process are different findings. +The runtime's `Memory access fault by GPU node-N ... on address 0x...` line is +the GPU one: outcome `MAF`, fault class `illegal_memory_access`, or +`read_only_page_fault` when the reason names a read-only page. The replay +process dying on a signal without printing any of that is the host one: outcome +`ABORT`, fault class `replay_crashed`, and it implicates no kernel, because +nothing about the workload was established. Report that as a failed run rather +than as the user's defect. + +An HSA queue abort (`HSA_STATUS_ERROR_EXCEPTION`, `ABORTED`, `MEMORY_FAULT`) is +not a hang: `MEMORY_FAULT` is a fault and the other two are hardware exceptions, +which an out-of-bounds access raises. The abort line carries the kernel but no +faulting address, so read the kernel from there. A genuine hang shows up as no +progress against the clock, which is what `HRR_REPLAY_TIMEOUT` reports; do not +report one on the strength of an HSA status alone. + +### A faulting ATen kernel needs the original failure signature + +PyTorch and vLLM reach the GPU through `<<<>>>` (`hipLaunchByPtr`), and those +kernels pass device pointers inside by-value structs: `vectorized_elementwise_kernel` +takes a `std::array`, `reduce_kernel` a config struct with pointers at +arbitrary offsets. Capture records those offsets and replay translates them, with +a defensive rescan for any the capture-time heuristic missed, so on a current +build these kernels replay faithfully and a fault on one is a real finding. + +Two things still make such a fault ambiguous: the detector is a value-based +heuristic, and an archive recorded before that support landed carries no offsets +at all, in which case replay launches with a capture-time address and faults on a +workload that is fine. Both look identical to a workload defect. + +So the fault class stays what the evidence says (`illegal_memory_access`), the +finding carries a note, and you **ask the user for their original failure +signature** before calling it their bug. If their run never faulted here, suspect +the recording. Faults on `hipModuleLaunchKernel`-launched kernels (hipBLASLt +GEMMs, custom HIP kernels) do not carry this ambiguity. + +### Kernel attribution + +Replay runs with `--sync-after-launch`, which `triage_archive.sh` adds for you. +Without it the GPU is serialized only once at the end, so a fault is reported but +not attributed and the finding has no failing event and no kernel. Pass +`--no-sync` only when throughput matters more than attribution. + +A clean replay implicates no kernel, so the finding reports none even though the +archive lists the kernels it ran. Never present a kernel next to a `PASS`. + +A memory fault can tear the process down before the failing dispatch is +attributed, leaving a log with no kernel at all. When the archive holds exactly +one kernel, the finding names it and says the name was inferred; confirm it with +`--sync-after-launch`, which stops replay on the faulting dispatch. With more +than one kernel it stays unknown rather than guessing. Names that `--info` +truncated to its column width are never used: a cut-off symbol cannot be looked +up or handed to a kernel developer. + ### Finding summary template (Step 5 / W4) Print a structured summary directly in the chat reply: diff --git a/projects/hrr/skills/decode-and-triage/evals/fixtures/info_crash.txt b/projects/hrr/skills/decode-and-triage/evals/fixtures/info_crash.txt new file mode 100644 index 000000000000..87289bb2a6eb --- /dev/null +++ b/projects/hrr/skills/decode-and-triage/evals/fixtures/info_crash.txt @@ -0,0 +1,29 @@ +HRR Archive: /captures/crash_v4.hrr/pid-79 +======================================== +Complete: NO (no shutdown trailer; capture likely crashed) +Recovered: 5 events +Events: 5 +Kernels: 1 +Blobs: 1 +Code Objects: 2 +Threads: 1 + +Event Type Breakdown: + Type Count + ---- ----- + hipDeviceSynchronize 1 + hipMalloc 1 + hipMemcpy 1 + hipModuleLaunchKernel 1 + hipModuleLoad 1 + +Kernel Summary (first 20): + ID Kernel Grid Block SharedMem + -- ------ ---- ----- --------- + 0 crash_oob [64,1,1] [64,1,1] 0 + +Kernel Call Counts: + Kernel Calls + ------ ----- + crash_oob 1 + diff --git a/projects/hrr/skills/decode-and-triage/evals/fixtures/info_pass.txt b/projects/hrr/skills/decode-and-triage/evals/fixtures/info_pass.txt new file mode 100644 index 000000000000..dfe707249e2f --- /dev/null +++ b/projects/hrr/skills/decode-and-triage/evals/fixtures/info_pass.txt @@ -0,0 +1,135 @@ +HRR Archive: /captures/qwen06b_offline_v4.hrr/pid-1 +======================================== +Complete: yes (clean shutdown) +Recovered: 185469 events +Events: 185469 +Kernels: 13233 +Blobs: 4458 +Code Objects: 33 +Threads: 2 + +Event Type Breakdown: + Type Count + ---- ----- + __hipPopCallConfiguration 12945 + __hipPushCallConfiguration 12945 + __hipRegisterFatBinary 4083 + hipDeviceGetAttribute 2827 + hipDeviceGetStreamPriorityRange 1 + hipDevicePrimaryCtxGetState 44 + hipDeviceSynchronize 1 + hipDriverGetVersion 1 + hipEventCreateWithFlags 66 + hipEventDestroy 64 + hipEventQuery 31 + hipEventRecord 131 + hipEventSynchronize 66 + hipFree 11 + hipFuncGetAttribute 12 + hipGetDevice 81383 + hipGetDeviceCount 4 + hipGetDevicePropertiesR0600 3295 + hipGetLastError 1241 + hipHostMalloc 29 + hipMalloc 107 + hipMemGetInfo 5 + hipMemcpyAsync 354 + hipMemcpyWithStream 509 + hipMemset 1 + hipMemsetAsync 32 + hipModuleLaunchKernel 13233 + hipModuleLoad 2 + hipModuleLoadDataEx 4 + hipModuleUnload 2 + hipPointerGetAttribute 448 + hipRuntimeGetVersion 2827 + hipSetDevice 48075 + hipStreamCreateWithPriority 1 + hipStreamGetCaptureInfo 509 + hipStreamIsCapturing 118 + hipStreamWaitEvent 32 + hipGetProcAddress 30 + +Kernel Summary (first 20): + ID Kernel Grid Block SharedMem + -- ------ ---- ----- --------- + 0 _ZN2at6native29vectorized_elementwise_kernelILi... [1,1,1] [256,1,1] 0 + 1 _ZN2at6native29vectorized_elementwise_kernelILi... [1,1,1] [256,1,1] 0 + 2 _ZN2at6native29vectorized_elementwise_kernelILi... [128,1,1] [256,1,1] 0 + 3 _ZN2at6native29vectorized_elementwise_kernelILi... [16,1,1] [256,1,1] 0 + 4 _ZN2at6native29vectorized_elementwise_kernelILi... [16,1,1] [256,1,1] 0 + 5 _ZN2at6native29vectorized_elementwise_kernelILi... [16,1,1] [256,1,1] 0 + 6 _ZN2at6native29vectorized_elementwise_kernelILi... [2,1,1] [256,1,1] 0 + 7 _ZN2at6native29vectorized_elementwise_kernelILi... [1,1,1] [256,1,1] 0 + 8 _ZN2at6native29vectorized_elementwise_kernelILi... [1,1,1] [256,1,1] 0 + 9 _ZN2at6native29vectorized_elementwise_kernelILi... [1,1,1] [256,1,1] 0 + 10 _ZN2at6native29vectorized_elementwise_kernelILi... [16,1,1] [256,1,1] 0 + 11 _ZN2at6native29vectorized_elementwise_kernelILi... [1,1,1] [256,1,1] 0 + 12 _ZN2at6native29vectorized_elementwise_kernelILi... [1,1,1] [256,1,1] 0 + 13 _ZN2at6native29vectorized_elementwise_kernelILi... [1,1,1] [256,1,1] 0 + 14 _ZN2at6native29vectorized_elementwise_kernelILi... [8192,1,1] [256,1,1] 0 + 15 _ZN2at6native29vectorized_elementwise_kernelILi... [4,1,1] [256,1,1] 0 + 16 _ZN2at6native29vectorized_elementwise_kernelILi... [1,1,1] [256,1,1] 0 + 17 _ZN2at6native29vectorized_elementwise_kernelILi... [1,1,1] [256,1,1] 0 + 18 _ZN2at6native29vectorized_elementwise_kernelILi... [1,1,1] [256,1,1] 0 + 19 _ZN2at6native29vectorized_elementwise_kernelILi... [16,1,1] [256,1,1] 0 + ... and 13213 more + +Kernel Call Counts: + Kernel Calls + ------ ----- + Cijk_Alik_Bljk_BBS_BH_Bias_HA_S_SAV_UserArgs_MT128x128x12... 28 + Cijk_Alik_Bljk_BBS_BH_Bias_HA_S_SAV_UserArgs_MT192x128x12... 28 + Cijk_Alik_Bljk_BBS_BH_Bias_HA_S_SAV_UserArgs_MT256x256x64... 114 + Cijk_Alik_Bljk_BBS_BH_Bias_HA_S_SAV_UserArgs_MT64x64x256_... 56 + _Z11wvSplitKrc_I14__hip_bfloat16Li64ELi16ELi4ELi8ELi1ELi1... 112 + _Z16wvSplitK_hf_sml_I14__hip_bfloat16Li64ELi1ELi16ELi8ELi... 1736 + _Z16wvSplitK_hf_sml_I14__hip_bfloat16Li64ELi2ELi16ELi8ELi... 1768 + _Z35paged_attention_ll4mi_reduce_kernelI14__hip_bfloat16S... 896 + _Z38paged_attention_ll4mi_QKV_mfma4_kernelI14__hip_bfloat... 896 + _ZN12_GLOBAL__N_129elementwise_kernel_with_indexIiZZZN2at... 2 + _ZN2at6native12_GLOBAL__N_121indexSelectSmallIndexIN3c108... 32 + _ZN2at6native12_GLOBAL__N_123cunn_SoftMaxForwardGmemILi4E... 2 + _ZN2at6native12_GLOBAL__N_126CatArrayBatchedCopy_contigIN... 1 + _ZN2at6native12_GLOBAL__N_143distribution_elementwise_gri... 2 + _ZN2at6native12_GLOBAL__N_143distribution_elementwise_gri... 2 + _ZN2at6native13reduce_kernelILi512ELi1ENS0_8ReduceOpIfNS0... 36 + _ZN2at6native24index_elementwise_kernelILi128ELi4EZNS0_16... 32 + _ZN2at6native24index_elementwise_kernelILi128ELi4EZNS0_16... 32 + _ZN2at6native24vectorized_gather_kernelILi16ElEEvPcS2_PT0... 4 + _ZN2at6native27unrolled_elementwise_kernelINS0_11FillFunc... 32 + _ZN2at6native27unrolled_elementwise_kernelINS0_21CUDAFunc... 32 + _ZN2at6native29vectorized_elementwise_kernelILi16ENS0_11F... 56 + _ZN2at6native29vectorized_elementwise_kernelILi16ENS0_11F... 3 + _ZN2at6native29vectorized_elementwise_kernelILi4ENS0_11Fi... 125 + _ZN2at6native29vectorized_elementwise_kernelILi4ENS0_11Fi... 43 + _ZN2at6native29vectorized_elementwise_kernelILi4ENS0_11Fi... 9 + _ZN2at6native29vectorized_elementwise_kernelILi4ENS0_13AU... 1 + _ZN2at6native29vectorized_elementwise_kernelILi4ENS0_13BU... 1 + _ZN2at6native29vectorized_elementwise_kernelILi4ENS0_13Bi... 2 + _ZN2at6native29vectorized_elementwise_kernelILi4ENS0_15CU... 32 + _ZN2at6native29vectorized_elementwise_kernelILi4ENS0_15CU... 32 + _ZN2at6native29vectorized_elementwise_kernelILi4EZNS0_21c... 4 + _ZN2at6native29vectorized_elementwise_kernelILi4EZNS0_25b... 1 + _ZN2at6native29vectorized_elementwise_kernelILi4EZNS0_34b... 34 + _ZN2at6native29vectorized_elementwise_kernelILi4EZZZNS0_1... 2 + _ZN2at6native29vectorized_elementwise_kernelILi4EZZZNS0_1... 1 + _ZN2at6native29vectorized_elementwise_kernelILi4EZZZNS0_1... 1 + _ZN2at6native29vectorized_elementwise_kernelILi4EZZZNS0_2... 1 + _ZN2at6native29vectorized_elementwise_kernelILi8ENS0_11Fi... 170 + _ZN2at6native32elementwise_kernel_manual_unrollILi128ELi4... 1 + _ZN2at6native32elementwise_kernel_manual_unrollILi128ELi4... 36 + _ZN2at6native32elementwise_kernel_manual_unrollILi128ELi4... 98 + _ZN2at6native32elementwise_kernel_manual_unrollILi128ELi4... 2 + _ZN2at6native32elementwise_kernel_manual_unrollILi128ELi4... 1 + _ZN2at6native32elementwise_kernel_manual_unrollILi128ELi4... 2 + _ZN4vllm15rms_norm_kernelIN3c108BFloat16ELi8ELi2EEEvPT_PK... 34 + _ZN4vllm15rms_norm_kernelIN3c108BFloat16ELi8ELi3EEEvPT_PK... 1904 + _ZN4vllm18act_and_mul_kernelIN3c108BFloat16E15__hip_bfloa... 952 + _ZN4vllm23rotary_embedding_kernelIN3c108BFloat16ELb1EEEvP... 952 + _ZN4vllm24reshape_and_cache_kernelI14__hip_bfloat16S1_LNS... 924 + _ZN4vllm25fused_add_rms_norm_kernelIN3c108BFloat16ELi8EEE... 1904 + _compute_slot_mapping_kernel 32 + _fwd_kernel 28 + _topk_topp_kernel 2 + diff --git a/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_aten_chevron.log b/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_aten_chevron.log new file mode 100644 index 000000000000..83467324b6af --- /dev/null +++ b/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_aten_chevron.log @@ -0,0 +1,13 @@ +[triage] archive=/data/llama_run.hrr/pid-680 replay=native +[triage] native replay playback=/opt/rocm/bin/hrr-playback GPU=3 --sync-after-launch +[HRR] Archive : 177203 events, 8214 kernels, 4733 blobs, 41 code objects +[HRR] Complete: yes (clean shutdown) +[HRR] [replay] Device state OK — beginning replay +[HRR] Event 41188: hipMallocAsync +[HRR] Event 41202: hipModuleLaunchKernel -> Kernel '_ZN2at6native29vectorized_elementwise_kernelILi4EZZZNS0_18add_kernel_cudaERNS_18TensorIteratorBaseEENKUlvE_clEvENKUlvE2_clEvEUlffE_NS_6detail5ArrayIPcLi3EEEEEviT0_T1_' OK +[HRR] Event 41266: hipMemcpyAsync +[HRR] Event 41310: hipLaunchKernel +:0:rocdevice.cpp :3608: Memory Fault Error [GPU index: 0, faulting addr: 0x7f8c11a00000, kernel: _ZN2at6native29vectorized_elementwise_kernelILi4EZZZNS0_18mul_kernel_cudaERNS_18TensorIteratorBaseEENKUlvE_clEvENKUlvE2_clEvEUlffE_NS_6detail5ArrayIPcLi3EEEEEviT0_T1_] +Memory access fault by GPU node-4 (Agent handle: 0x55d1a2f00c40) on address 0x7f8c11a00000. Reason: Unknown. +Aborted (core dumped) +[triage] native replay exit=134 diff --git a/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_hang_timeout.log b/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_hang_timeout.log new file mode 100644 index 000000000000..f8b4c10c27e5 --- /dev/null +++ b/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_hang_timeout.log @@ -0,0 +1,8 @@ +[HRR] Archive : 5 events, 1 kernels, 1 blobs, 2 code objects +[HRR] Threads : 1 captured +[HRR] Device : AMD Radeon Graphics (gfx950:sramecc+:xnack-) +[HRR] Mode : single-threaded +[HRR] [replay] Device state OK — beginning replay +[HRR] Pre-loading 2 code objects... +[HRR] All code objects pre-loaded OK. +[triage] replay timed out after 1800s diff --git a/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_memory_fault.log b/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_memory_fault.log new file mode 100644 index 000000000000..a926b585b7e0 --- /dev/null +++ b/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_memory_fault.log @@ -0,0 +1,3 @@ +[HRR] Archive has no clean-shutdown trailer (capture likely crashed); recovered 5 events +Memory access fault by GPU node-2 (Agent handle: 0x55a197628600) on address 0x7f91da000000. Reason: Unknown. +GPU coredump: execvp failed: No such file or directory diff --git a/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_pass.log b/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_pass.log new file mode 100644 index 000000000000..baa2e98612a4 --- /dev/null +++ b/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_pass.log @@ -0,0 +1,20 @@ +[HRR] NOOP playback handler called for hipDevicePrimaryCtxGetState — this API is not replayed; results may differ from capture. +[HRR] NOOP playback handler called for hipGetProcAddress — this API is not replayed; results may differ from capture. +[HRR] NOOP playback handler called for hipFuncGetAttribute — this API is not replayed; results may differ from capture. +[HRR] NOOP playback handler called for hipPointerGetAttribute — this API is not replayed; results may differ from capture. +[HRR] Archive : 185469 events, 13233 kernels, 4458 blobs, 33 code objects +[HRR] Threads : 2 captured +[HRR] Device : AMD Radeon Graphics (gfx950:sramecc+:xnack-) +[HRR] Mode : single-threaded +[HRR] [replay] Device memory: 257418 MB free / 258032 MB total +[HRR] [replay] Device state OK — beginning replay +[HRR] Pre-loading 33 code objects... +[HRR] All code objects pre-loaded OK. + +[HRR] -- Replay summary ------------------------------ +[HRR] Wall time : 39145.5 ms +[HRR] Threads used : 1 +[HRR] Kernels launched: 13233 +[HRR] Graphs launched : 0 +[HRR] D2H checks : 32 pass (32 exact, 0 within tol), 0 fail, 0 skipped +[HRR] PASS diff --git a/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_queue_abort_aten.log b/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_queue_abort_aten.log new file mode 100644 index 000000000000..ea74cde7ed38 --- /dev/null +++ b/projects/hrr/skills/decode-and-triage/evals/fixtures/replay_queue_abort_aten.log @@ -0,0 +1,14 @@ +[HRR] Archive has no clean-shutdown trailer (capture likely crashed); recovered 2727 events +[HRR] NOOP playback handler called for hipDevicePrimaryCtxGetState — this API is not replayed; results may differ from capture. +[HRR progress] elapsed_s=0.0 seq=1301 kernels=1 d2h_pass=0 d2h_fail=0 d2h_attempted=0 last="_ZN2at6native29vectorized_elementwise_kernelILi4ENS0_11FillFunctorIfEESt5arrayIPcLm1EEEEviT0_T1_" +Queue error: HSA_STATUS_ERROR_EXCEPTION: An HSAIL operation resulted in a hardware exception. +GPU coredump: Pipe handler '/usr/share/apport/apport' not found or not executable. +Falling back to file-based dump. Set HSA_COREDUMP_PATTERN to override. +VGPU=0x5617c727ec30 SWq=0x7f69e8266000, HWq=0x7f6109e00000, id=1 + Dispatch Header =0xb02 (type=2, barrier=1, acquire=1, release=1), setup=3 + grid=[256, 1, 1], workgroup=[256, 1, 1] + private_seg_size=0, group_seg_size=0 + kernel_obj=0x7f69de8aaa40, kernarg_address=0x0x7f60fea00100 + completion_signal=0x0 + rptr=18, wptr=20 +:0:rocdevice.cpp :4312: 3445930657021 us: Callback: Queue 0x7f6109e00000 aborting with error : HSA_STATUS_ERROR_EXCEPTION: An HSAIL operation resulted in a hardware exception. code: 0x1016 [host: 3d890059944d, GPU index: 0, kernel: void at::native::(anonymous namespace)::indexSelectSmallIndex(at::cuda::detail::TensorInfo, at::cuda::detail::TensorInfo, at::cuda::detail::TensorInfo, int, int, unsigned int, long)] diff --git a/projects/hrr/skills/decode-and-triage/evals/fixtures/rocm_smi_vram.txt b/projects/hrr/skills/decode-and-triage/evals/fixtures/rocm_smi_vram.txt new file mode 100644 index 000000000000..a8e9667e3a4c --- /dev/null +++ b/projects/hrr/skills/decode-and-triage/evals/fixtures/rocm_smi_vram.txt @@ -0,0 +1,7 @@ +====================== ROCm System Management Interface ====================== +================================ Memory Usage ================================ +GPU[0] : VRAM Total Memory (B): 274877906944 +GPU[0] : VRAM Total Used Memory (B): 264877906944 +GPU[1] : VRAM Total Memory (B): 274877906944 +GPU[1] : VRAM Total Used Memory (B): 1073741824 +============================== End of ROCm SMI Log =========================== diff --git a/projects/hrr/skills/decode-and-triage/evals/fixtures/version_mismatch.log b/projects/hrr/skills/decode-and-triage/evals/fixtures/version_mismatch.log new file mode 100644 index 000000000000..523aa2011f1e --- /dev/null +++ b/projects/hrr/skills/decode-and-triage/evals/fixtures/version_mismatch.log @@ -0,0 +1 @@ +[HRR] Version mismatch: file=3 reader=4 diff --git a/projects/hrr/skills/decode-and-triage/scripts/analyze_replay_finding.py b/projects/hrr/skills/decode-and-triage/scripts/analyze_replay_finding.py index d0a15d6652e8..81c4c0433cf3 100755 --- a/projects/hrr/skills/decode-and-triage/scripts/analyze_replay_finding.py +++ b/projects/hrr/skills/decode-and-triage/scripts/analyze_replay_finding.py @@ -29,17 +29,72 @@ r"Memory access fault by GPU node-(\d+).*on address (0x[0-9a-fA-F]+)\.\s*" r"Reason:\s*([^.\n]+)" ) +# The leading fields of this bracket vary by ROCm build -- some emit `host:`, +# some start at `GPU index:` -- so anchor on the two fields actually consumed +# rather than on the whole prefix. Requiring `host:` dropped the kernel name on +# every build that omits it, which is the one field the report exists to give. RE_MEM_FAULT_ERR = re.compile( - r"Memory Fault Error \[host: [^,]+, GPU index: \d+, faulting addr: (0x[0-9a-fA-F]+), " - r"kernel: ([^\]]+)\]" + r"Memory Fault Error \[[^\]]*?faulting addr: (0x[0-9a-fA-F]+), kernel: ([^\]]+)\]" +) +RE_HSA_STATUS = re.compile(r"HSA_STATUS_ERROR_(MEMORY_FAULT|ABORTED|EXCEPTION)") +# The runner bounds the replay and records the fact when it had to stop it. +# This is the only signal a hang leaves: it makes no progress and prints +# nothing, so without the marker the archive yields no finding at all. +RE_REPLAY_TIMEOUT = re.compile(r"replay timed out after (\d+)s") +# The replay process dying on a signal leaves the log truncated and nothing +# else, so the runner records it the same way. Read on its own it says the run +# failed, not that the workload did: no kernel was established as at fault. +RE_REPLAY_SIGNAL = re.compile(r"replay killed by signal (\d+)") +# A queue abort carries its own bracket, with the kernel but no faulting +# address, so the memory-fault regex above cannot see it. Observed on an +# out-of-bounds ATen gather, where this was the only line naming the culprit. +RE_QUEUE_ABORT_KERNEL = re.compile( + r"aborting with error[^\[\n]*\[[^\]]*?kernel: ([^\]]+)\]" ) -RE_HANG = re.compile(r"HSA_STATUS_ERROR_(MEMORY_FAULT|ABORTED|EXCEPTION)") RE_PASS = re.compile(r"\[HRR\] PASS\b") RE_FAIL = re.compile(r"\[HRR\] FAIL\b") RE_ARCHIVE_RECOVERED = re.compile( r"recovered (\d+) events|Archive : (\d+) events, (\d+) kernels, (\d+) blobs, (\d+) code objects" ) -RE_ARCHIVE_COMPLETE = re.compile(r"Complete:\s+(YES|NO)") +# `--info` prints `Complete: yes (clean shutdown)` or `Complete: NO (no +# shutdown trailer; capture likely crashed)`, so the verdict is case-mixed and +# always carries a trailing explanation. +RE_ARCHIVE_COMPLETE = re.compile(r"Complete:\s+(yes|no)\b", re.IGNORECASE) +# `--info` reports the archive as labelled fields, one per line, while a replay +# run reports the same totals on a single `[HRR] Archive :` line. +RE_INFO_EVENTS = re.compile(r"^Events:\s+(\d+)\s*$", re.MULTILINE) +RE_INFO_KERNELS = re.compile(r"^Kernels:\s+(\d+)\s*$", re.MULTILINE) +RE_INFO_RECOVERED = re.compile(r"^Recovered:\s+(\d+)\s+events\s*$", re.MULTILINE) +# Short archives print no `Kernels:` total and report launches only in the API +# call-count block. Without this the total stays unknown and the single-kernel +# inference in finalize() can never fire. +RE_INFO_LAUNCH_COUNT = re.compile(r"\bhip\w*LaunchKernel\s+(\d+)\b") +# Rows of the `--info` kernel summary table: name, grid, block, with an optional +# leading id, since some builds omit the id column. A memory fault can kill the +# replay before any per-launch attribution reaches the log, and then this table +# is the only record of what the archive ran. The name must start with a letter +# or underscore, which is what keeps a bare id from being read as a symbol now +# that the id is optional. +RE_INFO_KERNEL_ROW = re.compile( + r"^[ \t]*(?:\d+[ \t]+)?([A-Za-z_][^\s\[]*)[ \t]+\[[\d,\s]+\][ \t]+\[[\d,\s]+\]", + re.MULTILINE, +) +# `--verbose` prints one line per replayed event. A GPU fault tears the process +# down before HRR writes its own Fatal line, so when a run was made verbose the +# last of these is the only record of the failing dispatch. The sync flags do +# not emit these lines: `hrr_playback.cpp` gates them on `ctx.verbose` alone. +RE_EVENT_PROGRESS = re.compile( + r"^[ \t]*(?:\[HRR\][ \t]*)?Event (\d+):[ \t]*(\w+)" + r"(?:[^\n]*?->[ \t]*Kernel '([^']+)')?", + re.MULTILINE, +) +# PyTorch/ATen kernels reach the GPU through `<<<>>>` (hipLaunchByPtr) and pass +# device pointers inside by-value structs. Capture records those and replay +# translates them, so these kernels do replay faithfully on a current build. The +# detector is still a value-based heuristic, and an archive recorded before it +# landed carries no such offsets at all, so a fault on one of these symbols +# earns a caveat in the finding, not a different verdict. +RE_ATEN_CHEVRON = re.compile(r"_ZN2at6native|at::native::") RE_CAPTURE_MAF = RE_MAF RE_D2H_SUMMARY = re.compile(r"D2H checks\s+: (\d+) pass.*?, (\d+) fail, (\d+) skipped") RE_KERNARG = re.compile(r"kernarg_address=(0x[0-9a-fA-F]+)") @@ -65,14 +120,19 @@ class Finding: grid: str | None = None workgroup: str | None = None gpu_node: str | None = None + replay_signal: int | None = None last_progress_kernel: str | None = None + last_event_kernel: str | None = None kernels_launched: int | None = None d2h_pass: int | None = None d2h_fail: int | None = None d2h_attempted: int | None = None archive_events: int | None = None archive_kernels: int | None = None + archive_kernel_names: list[str] = field(default_factory=list) archive_complete: str | None = None + archive_format_version: int | None = None + reader_format_version: int | None = None capture_hip_so: str | None = None capture_hip_runtime_version: str | None = None capture_comgr_version: str | None = None @@ -88,12 +148,27 @@ def to_dict(self) -> dict[str, Any]: def _classify(text: str, finding: Finding) -> str: if RE_VERSION_MISMATCH.search(text): return "version_mismatch" + # A replay the runner had to stop made no progress against the clock, which + # is what a hang is. This outranks the rest: whatever partial output the + # replay printed before stalling does not describe why it stalled. + if RE_REPLAY_TIMEOUT.search(text): + return "hang" if RE_PASS.search(text): if finding.d2h_fail and finding.d2h_fail > 0: return "nan_inf_divergence" return "replay_pass" if "out of memory" in text.lower() or "hipErrorOutOfMemory" in text: return "replay_oom" + # A GPU memory fault has to be classified before the generic abort branch. + # Surfacing a fault through --sync-after-event makes the runtime print the + # memory-fault line and hrr-playback print "Fatal: GPU error after ..." for + # the same fault, so testing the abort first would report every fault as a + # plain API error, and that is exactly the mode used to localize a fault. + if RE_MAF.search(text) or RE_MEM_FAULT_ERR.search(text): + reason = (finding.fault_reason or "").lower() + if "read-only" in reason: + return "read_only_page_fault" + return "illegal_memory_access" if ( RE_FATAL_EVENT.search(text) or RE_FATAL_GPU.search(text) @@ -102,17 +177,29 @@ def _classify(text: str, finding: Finding) -> str: if "out of memory" in text.lower(): return "replay_oom" return "replay_fatal_api" - if RE_MAF.search(text) or RE_MEM_FAULT_ERR.search(text): - reason = (finding.fault_reason or "").lower() - if "read-only" in reason: - return "read_only_page_fault" - return "illegal_memory_access" - if RE_HANG.search(text) and not RE_PASS.search(text): - return "hang" + # An HSA queue abort is not a hang. MEMORY_FAULT says so in as many words, + # and EXCEPTION is a hardware exception, which an out-of-bounds access + # raises. Reporting either as a hang sends the reader after stalled work + # that never existed and drops the kernel the abort just named. A real hang + # shows up as no progress against the clock, which is what the replay + # timeout above reports. + hsa = RE_HSA_STATUS.search(text) + if hsa and not RE_PASS.search(text): + return ( + "illegal_memory_access" + if hsa.group(1) == "MEMORY_FAULT" + else "replay_aborted" + ) if RE_FAIL.search(text) or (finding.d2h_fail and finding.d2h_fail > 0): return "nan_inf_divergence" if "Replay aborted" in text or "aborting replay" in text: return "replay_aborted" + # Last, so that a log which explains its own stop is believed first: a + # memory fault also dies on a signal, and there the fault line is the + # answer. On its own the signal says the replay process died without + # reaching a verdict, which is a failure of the run and not of the workload. + if RE_REPLAY_SIGNAL.search(text): + return "replay_crashed" return "unknown" @@ -128,7 +215,10 @@ def _kernel_family(name: str | None) -> str | None: if sk: parts.append("streamk" if "SK3" in sk else "streamk_variant") return "/".join(parts) - if name.startswith("_ZN"): + # Mangled and demangled forms of the same ATen symbols both occur: the + # memory-fault line prints the mangled name, the queue-abort line prints + # the demangled signature. + if name.startswith("_ZN") or "at::native::" in name: return "pytorch_kernel" return "other" @@ -149,10 +239,43 @@ def parse_text(text: str, source: str, finding: Finding) -> Finding: m = RE_ARCHIVE_COMPLETE.search(text) if m: - finding.archive_complete = m.group(1) + finding.archive_complete = m.group(1).lower() + + for regex, attr in ( + (RE_INFO_RECOVERED, "archive_events"), + (RE_INFO_EVENTS, "archive_events"), + (RE_INFO_KERNELS, "archive_kernels"), + ): + m = regex.search(text) + if m: + setattr(finding, attr, int(m.group(1))) + + if finding.archive_kernels is None: + m = RE_INFO_LAUNCH_COUNT.search(text) + if m: + finding.archive_kernels = int(m.group(1)) + + for name in RE_INFO_KERNEL_ROW.findall(text): + # The table truncates long names to its column width, and a truncated + # symbol is worse than none: it cannot be looked up or handed over. + if name.endswith("...") or name in finding.archive_kernel_names: + continue + finding.archive_kernel_names.append(name) + + m = RE_HSA_STATUS.search(text) + if m and not RE_PASS.search(text): + note = f"the queue aborted with HSA_STATUS_ERROR_{m.group(1)}" + if note not in finding.notes: + finding.notes.append(note) + + m = RE_REPLAY_SIGNAL.search(text) + if m: + finding.replay_signal = int(m.group(1)) m = RE_VERSION_MISMATCH.search(text) if m: + finding.archive_format_version = int(m.group(1)) + finding.reader_format_version = int(m.group(2)) finding.notes.append( f"archive wire version {m.group(1)} does not match hrr-playback reader {m.group(2)}" ) @@ -165,7 +288,11 @@ def parse_text(text: str, source: str, finding: Finding) -> Finding: finding.d2h_fail = int(m.group(4)) finding.d2h_attempted = int(m.group(5)) last_prog = m.group(6) - finding.last_progress_kernel = last_prog + # Only when this input had progress lines. Assigning unconditionally let the + # archive `--info` pass, which has none, wipe the kernel the replay log had + # already recorded, and the default pipeline always parses both. + if last_prog is not None: + finding.last_progress_kernel = last_prog for m in (RE_FATAL_EVENT, RE_FATAL_GPU): hit = m.search(text) @@ -175,6 +302,17 @@ def parse_text(text: str, source: str, finding: Finding) -> Finding: finding.failing_api = hit.group(3) break + last_event = None + for m in RE_EVENT_PROGRESS.finditer(text): + last_event = m + if last_event is not None: + # An HRR Fatal line names the failing event exactly; this is only the + # last event that started, so it never overrides one. + if finding.failing_call_index is None: + finding.failing_call_index = int(last_event.group(1)) + finding.failing_api = last_event.group(2) + finding.last_event_kernel = last_event.group(3) + m = RE_MAF.search(text) if m: finding.gpu_node = m.group(1) @@ -186,6 +324,11 @@ def parse_text(text: str, source: str, finding: Finding) -> Finding: finding.fault_address = finding.fault_address or m.group(1) finding.kernel_name = m.group(2).strip() + if not finding.kernel_name: + m = RE_QUEUE_ABORT_KERNEL.search(text) + if m: + finding.kernel_name = m.group(1).strip() + if not finding.kernel_name: cijk = RE_CIJK.search(text) if cijk: @@ -210,16 +353,27 @@ def parse_text(text: str, source: str, finding: Finding) -> Finding: finding.fault_class = new_class new_outcome = finding.outcome - if RE_PASS.search(text): + if RE_REPLAY_TIMEOUT.search(text): + new_outcome = "HANG" + elif RE_PASS.search(text): new_outcome = "PASS" elif RE_MAF.search(text) or RE_MEM_FAULT_ERR.search(text): new_outcome = "MAF" elif RE_FAIL.search(text): new_outcome = "FAIL" + elif RE_HSA_STATUS.search(text): + # A queue abort is a GPU-side stop, so it is never UNKNOWN. Its own + # status says which: MEMORY_FAULT is a fault, the rest are aborts. + new_outcome = ( + "MAF" + if RE_HSA_STATUS.search(text).group(1) == "MEMORY_FAULT" + else "ABORT" + ) elif ( "aborting replay" in text or RE_FATAL_EVENT.search(text) or RE_VERSION_MISMATCH.search(text) + or RE_REPLAY_SIGNAL.search(text) ): new_outcome = "ABORT" elif finding.outcome == "UNKNOWN": @@ -229,6 +383,90 @@ def parse_text(text: str, source: str, finding: Finding) -> Finding: return finding +def finalize(finding: Finding) -> Finding: + """Settle kernel attribution once every input has been parsed. + + Attribution cannot be decided per input: the replay log and the archive + `--info` dump each hold half of the evidence, and which half arrives first + depends on how the caller was invoked. + """ + # A clean replay implicates no kernel. The archive still lists the kernels + # it ran, and a GEMM matched out of that listing would sit in the report + # next to a pass as though it were a culprit. + if finding.fault_class == "replay_pass": + finding.kernel_name = None + finding.kernel_family = None + finding.last_event_kernel = None + return finding + + # The replay process died without reaching a verdict, so nothing here is a + # statement about the workload. Inferring a kernel from the archive would + # hand over a culprit for a crash of the replay itself. + if finding.fault_class == "replay_crashed": + finding.kernel_name = None + finding.kernel_family = None + finding.notes.append( + f"the replay process was killed by signal {finding.replay_signal} " + f"without printing a verdict, so no kernel is implicated and the " + f"workload is untested. Re-run the replay; if it dies the same way " + f"again, this is a defect in hrr-playback or its environment rather " + f"than in the captured workload." + ) + return finding + + # Under --sync-after-launch the last launch to start is the one that + # faulted, so it stands in when the runtime's fault line carried no kernel. + if not finding.kernel_name and finding.last_event_kernel: + finding.kernel_name = finding.last_event_kernel + finding.notes.append( + f"kernel name taken from the last launch to start before the fault " + f"({finding.last_event_kernel}); the runtime fault line named no " + f"kernel. Valid only for a replay run with --verbose, which is what " + f"prints those per-event lines." + ) + + # A memory fault can tear the process down before the failing dispatch is + # attributed, leaving a log with no kernel at all. When the archive holds + # exactly one kernel, that kernel is the one that faulted. More than one + # stays unknown: picking among several would be a guess. + if ( + not finding.kernel_name + and finding.archive_kernels == 1 + and len(finding.archive_kernel_names) == 1 + ): + finding.kernel_name = finding.archive_kernel_names[0] + finding.notes.append( + f"kernel name inferred from the archive, which contains exactly one " + f"kernel ({finding.kernel_name}); the replay log carried no " + f"per-launch attribution. Re-run with --sync-after-launch to " + f"confirm the faulting dispatch directly." + ) + + # A `<<<>>>`-launched ATen kernel passes device pointers inside by-value + # structs. Current capture records those offsets and replay translates them, + # so this is not automatically a recording artefact, but the detector is a + # heuristic and an archive taken before it landed carries no offsets at all. + # Both failure modes look exactly like a workload fault, so flag the + # ambiguity rather than resolving it either way. + if finding.fault_class in ( + "illegal_memory_access", + "read_only_page_fault", + "replay_aborted", + ) and RE_ATEN_CHEVRON.search(finding.kernel_name or ""): + finding.notes.append( + "the faulting kernel is an ATen kernel launched through <<<>>> " + "(hipLaunchByPtr), which passes device pointers inside by-value " + "structs. Replay translates those via a value-based heuristic, and " + "an archive recorded before that support landed has none recorded " + "at all, so an untranslated pointer here would fault exactly like a " + "workload defect. Confirm against the user's original failure " + "signature before reporting this as their bug." + ) + + finding.kernel_family = _kernel_family(finding.kernel_name) + return finding + + def run_archive_info(archive: Path, hrr_playback: str | None) -> str: play = hrr_playback or "hrr-playback" try: @@ -270,11 +508,16 @@ def render_markdown(f: Finding) -> str: f"- **Kernels launched**: {f.kernels_launched or 'n/a'}", f"- **D2H**: pass={f.d2h_pass or 0} fail={f.d2h_fail or 0} attempted={f.d2h_attempted or 0}", f"- **Last progress kernel**: `{f.last_progress_kernel or 'n/a'}`", + f"- **Last launch before fault**: `{f.last_event_kernel or 'n/a'}`", "", "## Archive / capture", f"- **Events**: {f.archive_events or 'n/a'}", f"- **Kernels (archive)**: {f.archive_kernels or 'n/a'}", + f"- **Kernel names (archive)**: {', '.join(f.archive_kernel_names) or 'n/a'}", f"- **Complete**: {f.archive_complete or 'n/a'}", + f"- **Archive / reader format**: " + f"{f.archive_format_version if f.archive_format_version is not None else 'n/a'}" + f" / {f.reader_format_version if f.reader_format_version is not None else 'n/a'}", f"- **Capture HIP**: `{f.capture_hip_so or 'n/a'}`", f"- **Capture HIP runtime**: `{f.capture_hip_runtime_version or 'n/a'}`", f"- **Capture comgr**: `{f.capture_comgr_version or 'n/a'}`", @@ -346,6 +589,8 @@ def main() -> int: ) finding.sources.append(str(arch)) + finalize(finding) + out = ( json.dumps(finding.to_dict(), indent=2) if args.format == "json" diff --git a/projects/hrr/skills/decode-and-triage/scripts/ensure_playback.sh b/projects/hrr/skills/decode-and-triage/scripts/ensure_playback.sh index f71631767187..c0aae44ae2d0 100755 --- a/projects/hrr/skills/decode-and-triage/scripts/ensure_playback.sh +++ b/projects/hrr/skills/decode-and-triage/scripts/ensure_playback.sh @@ -72,6 +72,11 @@ build_playback() { export_playback_env() { local play="$1" ld_parts=() export HRR_PLAYBACK="$play" + # An in-tree ROCR lib dir, when the caller points at one, must precede the + # packaged runtime. check_replay_compat.py, replay_docker.sh and + # triage_archive.sh read the same variable; resolving it from a CLR build + # tree is gone with the standalone layout, so it is taken from the caller. + [[ -n "${ROCR_LIB:-}" && -d "${ROCR_LIB}" ]] && ld_parts+=("$ROCR_LIB") [[ -d "$ROCM_PATH/lib" ]] && ld_parts+=("$ROCM_PATH/lib") if [[ ${#ld_parts[@]} -gt 0 ]]; then export LD_LIBRARY_PATH="$(IFS=:; echo "${ld_parts[*]}")${LD_LIBRARY_PATH:+:$LD_LIBRARY_PATH}" diff --git a/projects/hrr/skills/decode-and-triage/scripts/test_analyze_replay_finding.py b/projects/hrr/skills/decode-and-triage/scripts/test_analyze_replay_finding.py index b42dbb5a7df7..eee4091b9a3d 100644 --- a/projects/hrr/skills/decode-and-triage/scripts/test_analyze_replay_finding.py +++ b/projects/hrr/skills/decode-and-triage/scripts/test_analyze_replay_finding.py @@ -57,11 +57,194 @@ def test_maf_not_overwritten_by_later_info_only_parse(self) -> None: self.assertEqual(finding.fault_class, "read_only_page_fault") self.assertEqual(finding.outcome, "MAF") + def test_a_gpu_fault_outranks_the_signal_that_killed_the_process(self) -> None: + """A memory fault aborts the process, so both markers are in the log.""" + text = ( + "Memory access fault by GPU node-2 (Agent handle: 0x1) on address " + "0x7f91da000000. Reason: Unknown.\n" + "[triage] replay killed by signal 6\n" + ) + finding = arf.Finding(outcome="UNKNOWN", fault_class="unknown") + arf.parse_text(text, "sample.log", finding) + self.assertEqual(finding.outcome, "MAF") + self.assertEqual(finding.fault_class, "illegal_memory_access") + def test_to_dict_json_serializable(self) -> None: finding = arf.Finding(outcome="PASS", fault_class="replay_pass") payload = json.dumps(finding.to_dict()) self.assertIn("replay_pass", payload) + def test_memory_fault_outranks_the_abort_line(self) -> None: + """A fault surfaced by --sync-after-event still reports as a fault. + + That path makes hrr_playback print its own abort line for the same + fault the runtime reports, so both lines appear in one log. + """ + text = ( + "Memory access fault by GPU node-2 (Agent handle: 0x1) on address " + "0x7f91da000000. Reason: Write access to a read-only page\n" + "[HRR] Fatal: GPU error after T0 Event 4210 (hipModuleLaunchKernel): " + "4 (hipErrorLaunchFailure) — aborting\n" + ) + finding = arf.Finding(outcome="UNKNOWN", fault_class="unknown") + arf.parse_text(text, "replay.log", finding) + self.assertEqual(finding.fault_class, "read_only_page_fault") + self.assertEqual(finding.outcome, "MAF") + + +class RecordedCaptureTests(unittest.TestCase): + """Checks against replay output recorded from a gfx950 host. + + The fixtures are unedited tool output, so a change in what hrr-playback + prints shows up here as a failing test rather than as a silently degraded + finding. + """ + + FIXTURES = SCRIPT_DIR.parent / "evals" / "fixtures" + + def _analyze(self, *names: str) -> arf.Finding: + finding = arf.Finding(outcome="UNKNOWN", fault_class="unknown") + for name in names: + path = self.FIXTURES / name + arf.parse_text(path.read_text(encoding="utf-8"), name, finding) + return arf.finalize(finding) + + def test_clean_replay_implicates_no_kernel(self) -> None: + finding = self._analyze("replay_pass.log", "info_pass.txt") + self.assertEqual(finding.outcome, "PASS") + self.assertEqual(finding.fault_class, "replay_pass") + self.assertIsNone(finding.kernel_name) + self.assertIsNone(finding.kernel_family) + + def test_clean_replay_carries_archive_totals(self) -> None: + finding = self._analyze("replay_pass.log", "info_pass.txt") + self.assertEqual(finding.archive_complete, "yes") + self.assertEqual(finding.archive_events, 185469) + self.assertEqual(finding.archive_kernels, 13233) + self.assertEqual(finding.d2h_fail, 0) + + def test_truncated_kernel_names_are_ignored(self) -> None: + """Every name in this capture's table is cut off by the column width.""" + finding = self._analyze("info_pass.txt") + self.assertEqual(finding.archive_kernel_names, []) + + def test_single_kernel_archive_attributes_the_fault(self) -> None: + finding = self._analyze("replay_memory_fault.log", "info_crash.txt") + self.assertEqual(finding.outcome, "MAF") + self.assertEqual(finding.fault_class, "illegal_memory_access") + self.assertEqual(finding.fault_address, "0x7f91da000000") + self.assertEqual(finding.kernel_name, "crash_oob") + self.assertEqual(finding.archive_complete, "no") + self.assertTrue(any("inferred from the archive" in n for n in finding.notes)) + + def test_a_crashed_replay_implicates_no_kernel(self) -> None: + """A signal death is a failed run, not a verdict on the workload. + + This archive holds exactly one kernel, so the inference that serves a + real fault would otherwise hand that kernel over as the culprit for a + crash of the replay process itself. + """ + finding = arf.Finding(outcome="UNKNOWN", fault_class="unknown") + arf.parse_text( + "[HRR] Replaying 5 events\n[triage] replay killed by signal 11\n", + "replay.log", + finding, + ) + arf.parse_text( + (self.FIXTURES / "info_crash.txt").read_text(encoding="utf-8"), + "info_crash.txt", + finding, + ) + finding = arf.finalize(finding) + self.assertEqual(finding.outcome, "ABORT") + self.assertEqual(finding.fault_class, "replay_crashed") + self.assertEqual(finding.replay_signal, 11) + self.assertIsNone(finding.kernel_name) + self.assertTrue(any("killed by signal 11" in n for n in finding.notes)) + + def test_short_memory_fault_form_still_names_the_kernel(self) -> None: + """Some ROCm builds omit `host:` and start the bracket at `GPU index:`.""" + finding = self._analyze("replay_aten_chevron.log") + self.assertEqual(finding.outcome, "MAF") + self.assertEqual(finding.fault_address, "0x7f8c11a00000") + self.assertIn("mul_kernel_cuda", finding.kernel_name or "") + + def test_aten_chevron_fault_carries_a_caveat_not_a_new_verdict(self) -> None: + """A `<<<>>>` ATen fault can be genuine, so the verdict stands. + + Capture records the pointers such kernels pass inside by-value structs + and replay translates them, so reclassifying would suppress a real + finding. An archive predating that support has none recorded, which + faults identically, so the ambiguity is flagged instead. + """ + finding = self._analyze("replay_aten_chevron.log") + self.assertEqual(finding.fault_class, "illegal_memory_access") + self.assertTrue( + any("hipLaunchByPtr" in n for n in finding.notes), + f"expected the ATen caveat, got {finding.notes}", + ) + + def test_last_launch_attributes_the_failing_event(self) -> None: + """Per-event lines are the only record when no Fatal line is written.""" + finding = self._analyze("replay_aten_chevron.log") + self.assertEqual(finding.failing_call_index, 41310) + self.assertEqual(finding.failing_api, "hipLaunchKernel") + + def test_queue_abort_is_not_a_hang(self) -> None: + """Recorded from an out-of-bounds ATen gather replayed on gfx950. + + The queue aborts with a hardware exception. Reading that as a hang + sends the reader after stalled work that never existed. + """ + finding = self._analyze("replay_queue_abort_aten.log") + self.assertNotEqual(finding.fault_class, "hang") + self.assertEqual(finding.fault_class, "replay_aborted") + self.assertEqual(finding.outcome, "ABORT") + self.assertTrue( + any("HSA_STATUS_ERROR_EXCEPTION" in n for n in finding.notes), + f"expected the raw HSA status in the notes, got {finding.notes}", + ) + + def test_queue_abort_keeps_the_kernel_it_named(self) -> None: + """That bracket carries a kernel but no faulting address.""" + finding = self._analyze("replay_queue_abort_aten.log") + self.assertIn("indexSelectSmallIndex", finding.kernel_name or "") + self.assertEqual(finding.kernel_family, "pytorch_kernel") + self.assertTrue( + any("hipLaunchByPtr" in n for n in finding.notes), + f"expected the ATen caveat, got {finding.notes}", + ) + + def test_a_stopped_replay_reports_a_hang(self) -> None: + """A hang prints nothing, so the runner's marker is the only signal.""" + finding = self._analyze("replay_hang_timeout.log") + self.assertEqual(finding.outcome, "HANG") + self.assertEqual(finding.fault_class, "hang") + self.assertIsNone(finding.kernel_name) + + def test_progress_kernel_survives_the_info_pass(self) -> None: + """The `--info` dump has no progress lines and must not erase them.""" + finding = arf.Finding(outcome="UNKNOWN", fault_class="unknown") + arf.parse_text( + '[HRR progress] elapsed_s=0.0 seq=4 kernels=1 d2h_pass=0 d2h_fail=0 ' + 'd2h_attempted=0 last="crash_oob"\n', + "replay.log", + finding, + ) + arf.parse_text( + (self.FIXTURES / "info_crash.txt").read_text(encoding="utf-8"), + "info", + finding, + ) + self.assertEqual(finding.last_progress_kernel, "crash_oob") + + def test_unreadable_archive_records_both_versions(self) -> None: + finding = self._analyze("version_mismatch.log") + self.assertEqual(finding.fault_class, "version_mismatch") + self.assertEqual(finding.archive_format_version, 3) + self.assertEqual(finding.reader_format_version, 4) + self.assertIsNone(finding.kernel_name) + if __name__ == "__main__": unittest.main() diff --git a/projects/hrr/skills/decode-and-triage/scripts/test_triage_archive.py b/projects/hrr/skills/decode-and-triage/scripts/test_triage_archive.py new file mode 100644 index 000000000000..d7524bacd920 --- /dev/null +++ b/projects/hrr/skills/decode-and-triage/scripts/test_triage_archive.py @@ -0,0 +1,233 @@ +#!/usr/bin/env python3 +"""Unit tests for triage_archive.sh (stdlib unittest, no GPU required). + +Device selection is exercised by lifting the `pick_gpu` function out of the +script and running it against recorded `rocm-smi` output, with a stub on PATH +standing in for the real tool. Picking the wrong device is not a cosmetic +mistake on a shared host: it sends the replay onto somebody else's card. +""" + +from __future__ import annotations + +import os +import re +import shutil +import subprocess +import tempfile +import unittest +from pathlib import Path + +SCRIPT_DIR = Path(__file__).resolve().parent +SCRIPT = SCRIPT_DIR / "triage_archive.sh" +FIXTURE = SCRIPT_DIR.parent / "evals" / "fixtures" / "rocm_smi_vram.txt" + + +def _shell_function(name: str) -> str: + text = SCRIPT.read_text(encoding="utf-8") + match = re.search( + rf"^{re.escape(name)}\(\)\s*\{{.*?^\}}", text, re.MULTILINE | re.DOTALL + ) + if match is None: + raise AssertionError(f"{name} not found in triage_archive.sh") + return match.group(0) + + +def _pick_gpu_function() -> str: + return _shell_function("pick_gpu") + + +@unittest.skipUnless(shutil.which("bash"), "bash is required") +class PickGpuTests(unittest.TestCase): + def _run_pick_gpu(self, smi_output: str, env_gpu: str | None = None) -> str: + with tempfile.TemporaryDirectory() as tmp: + stub_dir = Path(tmp) + data = stub_dir / "vram.txt" + data.write_text(smi_output, encoding="utf-8") + stub = stub_dir / "rocm-smi" + stub.write_text(f'#!/bin/sh\ncat "{data}"\n', encoding="utf-8") + stub.chmod(0o755) + + env = dict(os.environ) + env["PATH"] = f"{stub_dir}{os.pathsep}{env.get('PATH', '')}" + env.pop("GPU", None) + if env_gpu is not None: + env["GPU"] = env_gpu + + proc = subprocess.run( + ["bash", "-c", f"{_pick_gpu_function()}\npick_gpu"], + capture_output=True, + text=True, + env=env, + check=True, + ) + return proc.stdout.strip() + + def test_selects_the_device_with_the_most_free_memory(self) -> None: + """The freest device is neither the first nor the largest here. + + Both devices report the same total, and the first is nearly full, so a + parse that mistakes total for free selects the wrong one. + """ + self.assertEqual( + self._run_pick_gpu(FIXTURE.read_text(encoding="utf-8")), "1" + ) + + def test_used_line_is_not_read_as_the_total_line(self) -> None: + """`VRAM Total Used Memory` also contains the word `Total`.""" + smi = ( + "GPU[0]\t\t: VRAM Total Memory (B): 100\n" + "GPU[0]\t\t: VRAM Total Used Memory (B): 90\n" + "GPU[1]\t\t: VRAM Total Memory (B): 100\n" + "GPU[1]\t\t: VRAM Total Used Memory (B): 10\n" + ) + self.assertEqual(self._run_pick_gpu(smi), "1") + + def test_explicit_gpu_env_wins(self) -> None: + self.assertEqual( + self._run_pick_gpu(FIXTURE.read_text(encoding="utf-8"), env_gpu="0"), "0" + ) + + +class ReplayMaskTests(unittest.TestCase): + def test_native_replay_masks_with_hip_visible_devices(self) -> None: + """hrr-playback is a HIP program, so the HIP mask is the one that applies. + + Setting ROCR_VISIBLE_DEVICES re-indexes devices underneath a HIP mask, + which can place the replay on a device other than the one picked. The + Windows and container paths already use the HIP mask. + """ + text = SCRIPT.read_text(encoding="utf-8") + self.assertIn('HIP_VISIBLE_DEVICES="$gpu"', text) + assignments = [ + line.strip() + for line in text.splitlines() + if "ROCR_VISIBLE_DEVICES=" in line + ] + self.assertEqual(assignments, [], "ROCR_VISIBLE_DEVICES must not be set") + + +def _bash_at_least(major: int, minor: int) -> bool: + """The scripts target Linux bash. Expanding an empty array under `set -u` + is an error before bash 4.4, which the macOS system bash still is.""" + bash = shutil.which("bash") + if not bash: + return False + out = subprocess.run( + [bash, "-c", "echo ${BASH_VERSINFO[0]}.${BASH_VERSINFO[1]}"], + capture_output=True, + text=True, + ).stdout.strip() + try: + got_major, got_minor = (int(part) for part in out.split(".")[:2]) + except ValueError: + return False + return (got_major, got_minor) >= (major, minor) + + +@unittest.skipUnless(shutil.which("bash"), "bash is required") +class RecordReplayStopTests(unittest.TestCase): + """A stop the replay does not explain itself has to reach the log. + + Both cases end the log mid-stream. Without the marker the analyzer reads + that truncation as insufficient signal and then looks for a kernel to + blame, which reports a crash of the replay as a fault in the workload. + """ + + def _record(self, rc: int) -> str: + with tempfile.TemporaryDirectory() as tmp: + log = Path(tmp) / "replay.log" + log.write_text("[HRR] Replaying 5 events\n", encoding="utf-8") + script = ( + f'{_shell_function("record_replay_stop")}\n' + f'record_replay_stop {rc} "{log}" >/dev/null\n' + ) + subprocess.run(["bash", "-c", script], check=True) + return log.read_text(encoding="utf-8") + + def test_a_timeout_is_recorded_as_a_timeout(self) -> None: + self.assertIn("replay timed out after", self._record(124)) + + def test_a_signal_death_is_recorded_with_its_signal(self) -> None: + self.assertIn("replay killed by signal 11", self._record(139)) + + def test_an_ordinary_failure_adds_nothing(self) -> None: + """A replay that exits with an error has already said why in the log.""" + self.assertEqual(self._record(1), "[HRR] Replaying 5 events\n") + + +@unittest.skipUnless(shutil.which("bash"), "bash is required") +class LibraryPathTests(unittest.TestCase): + def test_packaged_playback_puts_its_own_lib_on_the_path(self) -> None: + """A playback shipped as bin/ and lib/ siblings, not a CLR build tree. + + Without its own lib dir the binary loads the system libamdhip64 and + fails on the symbols it was built against, which takes out the + metadata-only path as well as replay. + """ + with tempfile.TemporaryDirectory() as tmp: + root = Path(tmp) + (root / "bin").mkdir() + (root / "lib").mkdir() + play = root / "bin" / "hrr-playback" + play.write_text("#!/bin/sh\nexit 0\n", encoding="utf-8") + play.chmod(0o755) + + env = dict(os.environ) + env["ROCM_PATH"] = str(root / "absent") + env.pop("LD_LIBRARY_PATH", None) + + script = ( + f'SCRIPT_DIR={root}\nROCM_PATH="${{ROCM_PATH}}"\n' + f'{_shell_function("setup_library_path")}\n' + f'setup_library_path "{play}"\necho "$LD_LIBRARY_PATH"\n' + ) + proc = subprocess.run( + ["bash", "-c", script], + capture_output=True, + text=True, + env=env, + check=True, + ) + self.assertIn(str(root / "lib"), proc.stdout.strip()) + + +@unittest.skipUnless(_bash_at_least(4, 4), "needs bash >= 4.4 (Linux target)") +class EnsurePlaybackTests(unittest.TestCase): + def test_existing_playback_is_returned_outside_a_clr_tree(self) -> None: + """A provided binary must be usable where no CLR source tree exists. + + The script runs under `set -e`, so a helper whose last statement is a + false conditional aborts it before the path is printed, and the caller + reports a build failure even though the binary was there all along. + """ + with tempfile.TemporaryDirectory() as tmp: + root = Path(tmp) + scripts = root / "scripts" + scripts.mkdir() + shutil.copy(SCRIPT_DIR / "ensure_playback.sh", scripts) + + play = root / "bin" / "hrr-playback" + play.parent.mkdir() + play.write_text("#!/bin/sh\nexit 0\n", encoding="utf-8") + play.chmod(0o755) + + env = dict(os.environ) + env["HRR_PLAYBACK"] = str(play) + env["ROCM_PATH"] = str(root / "absent") + for stale in ("CLR_BUILD", "CLR_ROOT", "HRR_ROOT", "ROCR_LIB"): + env.pop(stale, None) + + proc = subprocess.run( + ["bash", str(scripts / "ensure_playback.sh"), "--build"], + capture_output=True, + text=True, + env=env, + ) + self.assertEqual( + proc.returncode, 0, f"ensure_playback failed: {proc.stderr}" + ) + self.assertEqual(proc.stdout.strip(), str(play)) + + +if __name__ == "__main__": + unittest.main() diff --git a/projects/hrr/skills/decode-and-triage/scripts/triage_archive.sh b/projects/hrr/skills/decode-and-triage/scripts/triage_archive.sh index bab581fac2f0..fef7d83460fd 100755 --- a/projects/hrr/skills/decode-and-triage/scripts/triage_archive.sh +++ b/projects/hrr/skills/decode-and-triage/scripts/triage_archive.sh @@ -11,6 +11,7 @@ COMPAT="$SCRIPT_DIR/check_replay_compat.py" ARCHIVE="" REPLAY_MODE="auto" +NO_SYNC=0 OUTPUT="" FORMAT="markdown" @@ -22,6 +23,7 @@ Options: --archive PATH pid-* HRR archive directory (required) --replay [MODE] Replay mode: native, docker, auto (default), or bare --replay (= native) --no-replay Metadata / --info only (no GPU replay or preflight block on replay) + --no-sync Replay without --sync-after-launch (faster, but a fault is not attributed) -o, --output PATH Write finding to PATH (default: HRR_TRIAGE_WORKDIR/-.finding.md) --format FORMAT markdown (default) or json -h, --help Show this help @@ -31,6 +33,7 @@ Environment (common): HRR_DOCKER_IMAGE Docker image for --replay docker / auto HRR_DOCKER_MOUNT_CLR=1 Overlay host CLR for docker replay (dev builds) GPU Replay GPU ordinal (default: auto-pick) + HRR_REPLAY_TIMEOUT Seconds before a stalled replay is stopped (default 1800, 0 disables) HRR_CONTINUE=1 Proceed after preflight HIP/comgr mismatch prompt HRR_SKIP_COMPAT=1 Skip manifest preflight EOF @@ -44,6 +47,7 @@ while [[ $# -gt 0 ]]; do if [[ $# -lt 2 || "$2" == --* ]]; then REPLAY_MODE="native"; shift else REPLAY_MODE="$2"; shift 2; fi ;; --no-replay) REPLAY_MODE="skip"; shift ;; + --no-sync) NO_SYNC=1; shift ;; -o|--output) OUTPUT="$2"; shift 2 ;; --format) FORMAT="$2"; shift 2 ;; *) echo "error: unknown arg: $1" >&2; exit 1 ;; @@ -76,6 +80,12 @@ setup_library_path() { if [[ "$bin_dir" == */bin ]]; then lib_dirs+=("$(cd "$bin_dir/../lib" 2>/dev/null && pwd || true)") fi + # A packaged playback ships as bin/ and lib/ siblings rather than inside a + # build tree. Without this its libamdhip64 is never on the path, so the + # binary loads the system one and fails on the symbols it was built against. + if [[ -d "$bin_dir/../lib" ]]; then + lib_dirs+=("$(cd "$bin_dir/../lib" && pwd)") + fi repo="$(cd "$SCRIPT_DIR/../../../../.." 2>/dev/null && pwd || true)" for p in "${ROCR_LIB:-}" "${repo:+$repo/projects/rocr-runtime/build-local/rocr/lib}"; do [[ -n "$p" && -f "$p/libhsa-runtime64.so.1" ]] || continue @@ -99,25 +109,80 @@ pick_gpu() { [[ -n "$idx" ]] || continue (( free > best_free )) && { best_free=$free; best=$idx; } done < <(rocm-smi --showmeminfo vram 2>/dev/null | awk ' - /GPU\[/ { gsub(/[^0-9]/,"",$1); idx=$1 } - /Used Memory/ { used=$NF } - /Total Memory/ { total=$NF; if (idx!="") { print idx, total-used; idx="" } }') + # The used line reads "VRAM Total Used Memory", so it also contains the + # word Total and must be tested first. Total and used arrive on separate + # lines whose order is not guaranteed, so collect both per device and + # subtract at END rather than on whichever line happens to land last. + /GPU\[/ { + id = $1; gsub(/[^0-9]/, "", id) + if ($0 ~ /Total Used Memory/) used[id] = $NF + else if ($0 ~ /Total Memory/) total[id] = $NF + } + END { + for (id in total) + if (id in used) print id, total[id] - used[id] + }') [[ -n "$best" ]] && { echo "[triage] GPU $best (most free VRAM)" >&2; echo "$best"; return; } fi echo "0" } +replay_sync_args() { + # Default replay serializes the GPU once at the end, so a fault is reported + # but not attributed to a launch: the finding then has no failing event and + # no kernel. Synchronizing after every launch is what makes the last launch + # line before the fault the culprit. Opt out with --no-sync when throughput + # matters more than attribution, for instance a long soak. + [[ "$NO_SYNC" == "1" ]] && return 0 + echo "--sync-after-launch" +} + +# A stop the replay does not explain itself has to be recorded here, because +# the log just ends where the process died. The analyzer would read that +# truncation as insufficient signal and then go looking for a kernel to blame +# for it, which is how a crash of the replay process ends up reported as a +# workload fault. 124 is what `timeout` reports; above 128 the shell is +# reporting death by signal 128+N. A signal is not on its own a verdict: a GPU +# memory fault also aborts, and there the log's own fault line is the better +# answer, so the classifier ranks these markers last. +record_replay_stop() { + local rc="$1" log="$2" + [[ -n "$log" ]] || return 0 + if [[ "$rc" == "124" ]]; then + echo "[triage] replay timed out after ${HRR_REPLAY_TIMEOUT:-1800}s" | tee -a "$log" >&2 + elif (( rc > 128 )); then + echo "[triage] replay killed by signal $((rc - 128))" | tee -a "$log" >&2 + fi +} + run_native_replay() { - local play="$1" log="$2" gpu + local play="$1" log="$2" gpu sync_args=() setup_library_path "$play" gpu="$(pick_gpu)" [[ -r /dev/kfd ]] || { echo "error: /dev/kfd not accessible" >&2; return 1; } - echo "[triage] native replay playback=$play GPU=$gpu" >&2 + read -r -a sync_args <<< "$(replay_sync_args)" + # A hung workload replays as a hang, and without a bound the replay never + # returns, so the analyzer never runs and the archive yields no finding at + # all. The bound belongs here, around the playback process: wrapping the + # container instead leaves the replay running inside it. Set + # HRR_REPLAY_TIMEOUT=0 to disable. + local timeout_s="${HRR_REPLAY_TIMEOUT:-1800}" runner=() + if [[ "$timeout_s" != "0" ]] && command -v timeout >/dev/null 2>&1; then + runner=(timeout "$timeout_s") + fi + echo "[triage] native replay playback=$play GPU=$gpu ${sync_args[*]}" >&2 set +e - ROCR_VISIBLE_DEVICES="$gpu" HIP_HRR_REPLAY_PROGRESS_SECONDS="${HIP_HRR_REPLAY_PROGRESS_SECONDS:-30}" \ - "$play" "$ARCHIVE" 2>&1 | tee "$log" + # hrr-playback is a HIP program, so HIP_VISIBLE_DEVICES is the mask that + # applies to it. Setting ROCR_VISIBLE_DEVICES re-indexes devices underneath a + # HIP mask, which can land the replay on a device other than the one picked. + HIP_VISIBLE_DEVICES="$gpu" HIP_HRR_REPLAY_PROGRESS_SECONDS="${HIP_HRR_REPLAY_PROGRESS_SECONDS:-30}" \ + ${runner[@]+"${runner[@]}"} "$play" "$ARCHIVE" ${sync_args[@]+"${sync_args[@]}"} 2>&1 | tee "$log" local rc=${PIPESTATUS[0]} - set -e + # Deliberately not re-enabling `set -e` here. The caller wraps this call in + # `set +e` precisely so a failing replay is survivable, and restores `set -e` + # afterwards. Re-arming it inside the function made the non-zero return fatal, + # so a replay that faulted killed the script before the finding was written: + # the skill produced nothing in exactly the case it exists for. echo "[triage] native replay exit=$rc" >&2 return "$rc" } @@ -172,6 +237,19 @@ if [[ "$mode" != "skip" && "$mode" == "native" && -x "$ENSURE" ]]; then exit 1 } export HRR_PLAYBACK +elif [[ "$mode" == "skip" && -x "$ENSURE" ]]; then + # Metadata-only still wants `hrr-playback --info`, which needs no GPU. Locate + # without --build so this never tries to compile; if there is no binary the + # analyzer simply reports the archive path, as before. + # Not a trailing `&&`: as the last statement of this branch it would become + # the `if` statement's exit status and, under `set -e`, end the script. + HRR_PLAYBACK="$("$ENSURE" 2>/dev/null || true)" + if [[ -n "$HRR_PLAYBACK" ]]; then + export HRR_PLAYBACK + # The library path is otherwise only prepared inside the native replay, so + # without this the analyzer finds the binary and then cannot load it. + setup_library_path "$HRR_PLAYBACK" + fi elif [[ "$mode" == "docker" && "${HRR_DOCKER_MOUNT_CLR:-0}" == "1" && -x "$ENSURE" ]]; then HRR_PLAYBACK="$("$ENSURE" --build)" || { echo "error: ensure_playback.sh --build failed for HRR_DOCKER_MOUNT_CLR=1" >&2 @@ -180,18 +258,23 @@ elif [[ "$mode" == "docker" && "${HRR_DOCKER_MOUNT_CLR:-0}" == "1" && -x "$ENSUR export HRR_PLAYBACK fi -REPLAY_GPU="${GPU:-$(pick_gpu)}" +REPLAY_GPU="" if [[ "$mode" != "skip" ]]; then + # Only when a device is actually going to be used: metadata-only needs no GPU + # and should not announce a choice it never makes. + REPLAY_GPU="${GPU:-$(pick_gpu)}" run_replay_preflight "$mode" "$REPLAY_GPU" fi if [[ "$mode" == "docker" ]]; then LOG="$WORKDIR/hrr-replay-${name}-${ts}.log" - set +e; "$REPLAY_DOCKER" --archive "$ARCHIVE" --log "$LOG" --gpu "$REPLAY_GPU"; set -e + set +e; "$REPLAY_DOCKER" --archive "$ARCHIVE" --log "$LOG" --gpu "$REPLAY_GPU"; replay_rc=$?; set -e + record_replay_stop "$replay_rc" "$LOG" elif [[ "$mode" == "native" ]]; then LOG="$WORKDIR/hrr-replay-${name}-${ts}.log" GPU="$REPLAY_GPU" - set +e; run_native_replay "$HRR_PLAYBACK" "$LOG"; set -e + set +e; run_native_replay "$HRR_PLAYBACK" "$LOG"; replay_rc=$?; set -e + record_replay_stop "$replay_rc" "$LOG" fi CMD=(python3 "$ANALYZER" --format "$FORMAT" --archive "$ARCHIVE" -o "$FINDING")