Files
2026-07-13 13:17:40 +08:00

474 lines
17 KiB
Python

# ABOUTME: Attaches perf record CPU profiling to GCS and raylet C++ processes.
# ABOUTME: Provides head-node profiling, worker-node actor-based profiling, and collapsed stack generation.
import os
import re
import shutil
import signal
import subprocess
import time
import ray
from ray.util.scheduling_strategies import NodeAffinitySchedulingStrategy
def _ensure_perf_available():
"""Check that perf is installed. Returns True if available."""
if shutil.which("perf"):
return True
print("WARNING: perf not found on PATH. Skipping CPU profiling.")
return False
def _ensure_perf_permissions():
"""Lower perf_event_paranoid so non-root users can record."""
try:
subprocess.run(
["sudo", "sysctl", "-w", "kernel.perf_event_paranoid=-1"],
check=True,
capture_output=True,
)
subprocess.run(
["sudo", "sysctl", "-w", "kernel.kptr_restrict=0"],
check=True,
capture_output=True,
)
except (subprocess.CalledProcessError, FileNotFoundError) as e:
print(f"WARNING: Failed to set perf permissions: {e}")
def find_pid(process_name, use_full=False, retries=15, interval=2):
"""Find a process PID by name with retries for startup races.
Args:
process_name: Process name to match.
use_full: If True, match against full command line (pgrep -f).
If False, match exact process name (pgrep -x).
retries: Number of retry attempts.
interval: Seconds between retries.
Returns:
PID as int, or None if not found after all retries.
"""
flag = "-f" if use_full else "-x"
for attempt in range(retries):
try:
result = subprocess.run(
["pgrep", flag, process_name],
capture_output=True,
text=True,
)
if result.returncode == 0:
pid = int(result.stdout.strip().split("\n")[0])
return pid
except (ValueError, IndexError):
pass
if attempt < retries - 1:
time.sleep(interval)
print(f"WARNING: Process '{process_name}' not found after {retries * interval}s")
return None
def start_profiling(pid, label, outdir):
"""Start perf record on a process.
Args:
pid: Target process ID.
label: Label for output files (e.g. "gcs", "raylet").
outdir: Directory for output files.
Returns:
(subprocess.Popen, IO, data_path) tuple, or (None, None, None) if perf
fails to start.
"""
node_ip = ray.util.get_node_ip_address().replace(".", "_")
os.makedirs(outdir, exist_ok=True)
data_path = f"{outdir}/perf_{label}_{node_ip}.data"
log_path = f"{outdir}/perf_{label}_{node_ip}.log"
cmd = [
"perf",
"record",
"-g",
"--call-graph",
"fp",
"-F",
"99",
"-p",
str(pid),
"-o",
data_path,
]
log_file = open(log_path, "w")
log_file.write(f"cmd: {' '.join(cmd)}\n")
log_file.write(f"target pid: {pid}\n")
log_file.flush()
try:
proc = subprocess.Popen(cmd, stdout=log_file, stderr=log_file)
except OSError as e:
log_file.write(f"Failed to start perf: {e}\n")
log_file.close()
print(f"WARNING: Failed to start perf for {label} (pid {pid}): {e}")
return None, None, None
# Give perf a moment to fail on startup.
time.sleep(1)
if proc.poll() is not None:
log_file.write(f"perf exited early with code {proc.returncode}\n")
log_file.close()
print(f"WARNING: perf failed to start for {label} (code {proc.returncode})")
return None, None, None
log_file.write(f"perf pid: {proc.pid}\n")
log_file.flush()
print(f"perf profiling started for {label} (target pid {pid}) -> {data_path}")
return proc, log_file, data_path
def stop_profiler(proc, log_file, timeout=15):
"""Stop a perf process gracefully.
Args:
proc: subprocess.Popen handle from start_profiling.
log_file: Log file handle from start_profiling.
timeout: Seconds to wait for perf to flush output.
"""
if proc is None:
return
print(f"Stopping perf (pid {proc.pid})...")
try:
# Use SIGTERM rather than SIGINT. perf record handles both for clean
# shutdown, but SIGINT can be ignored when perf lacks a controlling
# terminal (common inside Ray actor worker processes).
os.kill(proc.pid, signal.SIGTERM)
proc.wait(timeout=timeout)
msg = f"perf exited with code {proc.returncode}"
print(msg)
if log_file:
log_file.write(msg + "\n")
except subprocess.TimeoutExpired:
msg = f"perf did not exit in {timeout}s, killing"
print(msg)
proc.kill()
if log_file:
log_file.write(msg + "\n")
except ProcessLookupError:
msg = "perf already exited"
print(msg)
if log_file:
log_file.write(msg + "\n")
finally:
if log_file:
log_file.flush()
log_file.close()
def _clean_func_name(name):
"""Strip hex offsets and clean up a function name from perf script output.
Removes trailing +0x... offsets and replaces semicolons (which conflict
with the collapsed stack delimiter) with colons.
"""
# Strip trailing +0xHEX offset
name = re.sub(r"\+0x[0-9a-f]+$", "", name)
# Replace semicolons in C++ names (template args, etc.)
name = name.replace(";", ":")
return name
def generate_collapsed_stacks(outdir, data_path=None):
"""Convert perf.data files to collapsed stack format.
Produces *_collapsed.txt next to each *.data. Must be run on a machine
whose kernel and runtime libraries match the one that recorded the data —
for Ray worker profiles this means the worker node itself, before its
/tmp/ray/session_* directory is torn down.
Args:
outdir: Directory to scan (ignored if data_path is given).
data_path: If set, convert only this single .data file. Otherwise
convert every perf_*.data under outdir that does not
already have a matching _collapsed.txt.
perf script output format:
command pid/tid [cpu] timestamp: event:
hex_addr func_name+0xoff (dso)
hex_addr func_name+0xoff (dso)
...
<blank line>
"""
import glob as globmod
if data_path is not None:
data_files = [data_path]
else:
data_files = globmod.glob(os.path.join(outdir, "perf_*.data"))
if not data_files:
print("No perf data files found to convert.")
return
# Regex for the header line: "command pid/tid [cpu] timestamp: event:"
header_re = re.compile(r"^\s*(\S+)\s+\d+")
for data_path in data_files:
name = os.path.basename(data_path).replace(".data", "")
collapsed_path = os.path.join(
os.path.dirname(data_path) or outdir, f"{name}_collapsed.txt"
)
if os.path.exists(collapsed_path):
print(f"Skipping {data_path}: {collapsed_path} already exists")
continue
print(f"Converting {data_path} -> {collapsed_path}")
try:
perf_script = subprocess.Popen(
["perf", "script", "-i", data_path],
stdout=subprocess.PIPE,
stderr=subprocess.DEVNULL,
)
with open(collapsed_path, "w") as out:
comm = ""
stack = []
for line in perf_script.stdout:
line = line.decode("utf-8", errors="replace").rstrip()
if line == "":
if stack:
prefix = comm + ";" if comm else ""
out.write(prefix + ";".join(reversed(stack)) + " 1\n")
stack = []
comm = ""
elif line and line[0] in (" ", "\t"):
# Stack frame: leading whitespace + hex_addr + func_name+0xoff (dso)
parts = line.strip().split(" ", 1)
if len(parts) >= 2:
addr, rest = parts
# Split trailing "(dso)" off the end if present.
# Stripped libs (libcudart, libcublas, libtorch
# extensions, etc.) yield "[unknown] (dso)" — keep
# the DSO basename so per-library time is visible.
dso = ""
if rest.endswith(")"):
paren = rest.rfind(" (")
if paren != -1:
dso = rest[paren + 2 : -1].strip()
rest = rest[:paren]
func = _clean_func_name(rest)
if func == "[unknown]":
if dso and dso not in ("unknown", "[unknown]"):
dso_base = os.path.basename(dso).replace(";", ":")
# "@0x..." rather than "+0x..." so the
# address survives collapsed_to_speedscope
# (which strips trailing +0xHEX offsets).
# analyze_pyspy_profile groups by DSO by
# default and shows the @addr with
# --detail-unknowns.
func = f"unk_{dso_base}@0x{addr}"
else:
func = f"unk_0x{addr}"
stack.append(func)
else:
# Header line: extract command name (thread)
m = header_re.match(line)
if m:
comm = m.group(1)
if stack:
prefix = comm + ";" if comm else ""
out.write(prefix + ";".join(reversed(stack)) + " 1\n")
perf_script.wait()
size = os.path.getsize(collapsed_path)
print(f" -> {collapsed_path} ({size} bytes)")
except Exception as e:
print(f" WARNING: Failed to convert {data_path}: {e}")
# ---------------------------------------------------------------------------
# Head-node profiling: GCS + local raylet
# ---------------------------------------------------------------------------
def start_head_node(outdir):
"""Start perf profiling on GCS and raylet processes on the head node.
Returns:
List of (proc, log_file, data_path) tuples for each started profiler.
"""
handles = []
if not _ensure_perf_available():
return handles
_ensure_perf_permissions()
gcs_pid = find_pid("gcs_server", use_full=True)
if gcs_pid:
handles.append(start_profiling(gcs_pid, "gcs", outdir))
raylet_pid = find_pid("raylet")
if raylet_pid:
handles.append(start_profiling(raylet_pid, "raylet", outdir))
return handles
def stop_head(handles):
"""Stop head-node perf profilers and convert their data to collapsed stacks.
Symbolization happens here (on the head) because the head's filesystem
is what produced the .data files.
Args:
handles: List of (proc, log_file, data_path) tuples from start_head_node.
"""
for proc, log_file, data_path in handles:
stop_profiler(proc, log_file)
if data_path and os.path.exists(data_path):
try:
generate_collapsed_stacks(
os.path.dirname(data_path), data_path=data_path
)
except Exception as e:
print(f"WARNING: head collapse failed for {data_path}: {e}")
# ---------------------------------------------------------------------------
# Worker-node profiling via Ray actors
# ---------------------------------------------------------------------------
@ray.remote(num_cpus=0, num_gpus=0)
class _RayletPerfProfiler:
"""Actor that profiles the local raylet with perf record.
Using an actor (not a task) so the head node can call stop() explicitly
before the job exits, giving perf a clean SIGTERM to finalize the data file.
"""
def __init__(self, outdir):
self._outdir = outdir
self._proc = None
self._log_file = None
self._data_path = None
def start(self):
if not _ensure_perf_available():
return False
_ensure_perf_permissions()
pid = find_pid("raylet")
if pid is None:
return False
self._proc, self._log_file, self._data_path = start_profiling(
pid, "raylet", self._outdir
)
return self._proc is not None
def stop(self):
if self._proc is not None:
print(
f"Actor stop() called, perf pid={self._proc.pid}, "
f"poll={self._proc.poll()}"
)
stop_profiler(self._proc, self._log_file, timeout=30)
# Convert to collapsed stacks on this worker node, while the local
# /tmp/ray/session_* runtime_env libs (libtorch, libcuda, etc.) are
# still on disk. If we defer this to the head, those DSOs are gone
# and ~every user-space frame resolves to [unknown].
if self._data_path and os.path.exists(self._data_path):
try:
generate_collapsed_stacks(self._outdir, data_path=self._data_path)
except Exception as e:
print(f"WARNING: worker collapse failed for {self._data_path}: {e}")
self._proc = None
self._log_file = None
self._data_path = None
def start_worker_nodes(outdir, num_cpu_workers=5, num_gpu_workers=5):
"""Launch perf profiling actors on a sample of worker nodes.
Args:
outdir: Shared storage directory for profile output.
num_cpu_workers: Number of CPU-only worker nodes to profile.
num_gpu_workers: Number of GPU worker nodes to profile.
Returns:
List of actor handles (for passing to stop_workers later).
"""
head_node_id = ray.get_runtime_context().get_node_id()
monitored_node_ids = set()
actors = []
cpu_count = 0
gpu_count = 0
target_count = num_cpu_workers + num_gpu_workers
stale_polls = 0
max_stale_polls = 30 # 30 * 2s = 60s with no new nodes
while (cpu_count + gpu_count) < target_count:
found_new = False
for node in ray.nodes():
if not node["Alive"] or node["NodeID"] in monitored_node_ids:
continue
if node["NodeID"] == head_node_id:
continue
has_gpu = node["Resources"].get("GPU", 0) > 0
if has_gpu and gpu_count >= num_gpu_workers:
continue
if not has_gpu and cpu_count >= num_cpu_workers:
continue
try:
actor = _RayletPerfProfiler.options(
scheduling_strategy=NodeAffinitySchedulingStrategy(
node_id=node["NodeID"], soft=False
),
).remote(outdir)
started = ray.get(actor.start.remote())
found_new = True
if started:
actors.append(actor)
monitored_node_ids.add(node["NodeID"])
if has_gpu:
gpu_count += 1
else:
cpu_count += 1
print(
f"Perf profiling raylet on {node['NodeManagerAddress']} "
f"(cpu={cpu_count}/{num_cpu_workers}, "
f"gpu={gpu_count}/{num_gpu_workers})"
)
else:
monitored_node_ids.add(node["NodeID"])
print(f"Perf failed to start on {node['NodeManagerAddress']}")
except Exception as e:
# Mark the node as monitored so we don't retry it forever.
monitored_node_ids.add(node["NodeID"])
print(f"Failed perf on {node['NodeManagerAddress']}: {e}")
if not found_new:
stale_polls += 1
if stale_polls >= max_stale_polls:
print(
f"Perf: no new worker nodes for {max_stale_polls * 2}s, "
f"proceeding with {cpu_count} CPU + {gpu_count} GPU "
f"({len(actors)} actors attached)"
)
break
else:
stale_polls = 0
time.sleep(2)
if (cpu_count + gpu_count) >= target_count:
print(f"Perf profiling active on {cpu_count} CPU + {gpu_count} GPU workers")
return actors
def stop_workers(actors):
"""Stop worker-node perf profilers.
Args:
actors: List of actor handles from start_worker_nodes.
"""
if not actors:
return
print(f"Stopping {len(actors)} worker perf profilers...")
ray.get([a.stop.remote() for a in actors])