aiml
SearchMy learning
Menu

Lesson 14 of 20Module 5

Investigate host overhead before changing GPU settings

Profile host operators around an actual Metal model forward. Read recorded events without treating CPU timings as GPU kernel measurements.

Prerequisites

Python, basic causal attention, and the preceding inference lessons.

By the end, you can

  • Investigate host overhead before changing GPU settings.
  • Explain the bottleneck, measurement boundary, and tradeoffs in this implementation.
  • Separate host operator events from GPU kernel and occupancy measurements.
Runtime
Python 3.12+
Dependencies
Offline checks have no external imports; live model execution uses torch 2.14.1 and transformers 5.20.2

Lab code, tests and fixtures (ZIP, 122 KB)Quiz check your understanding

Progress is saved in this browser.

When you need this. A busy API has queued requests, yet responses remain slow. An accelerator utilization percentage alone cannot tell whether the limit is tokenization, host dispatch, synchronization, memory transfer, or model computation. Start with a timeline and a controlled measurement.

What you run. Actual CPU profiler events around Metal inference and an offline record validator. No NVIDIA utilization, occupancy, or CUDA graph result is claimed.

This lesson builds on choose a latency-throughput operating point.

Collect a focused execution profile

A device can be busy without efficiently using its arithmetic units, and a low average busy fraction can hide short bursts. Host calls such as converting a device tensor to a Python scalar can introduce synchronization. Separate queueing, CPU preprocessing, dispatch, and device work before proposing a fix.

The real profiler records CPU operator events around a synchronized local model forward. Those event durations are not GPU kernel durations or SM occupancy. The report does not invent a busy fraction or identify these events as nvidia-smi samples.

Model forwardCPU event profilerOperator recordsoperator callsevent dataModel forwardCPU event profilerOperator recordsoperatorcallsevent data
Follow the named data through the downloadable program. The article identifies whether the result is measured execution, a controlled fixture, or a planning estimate.

profile_live.py records actual operator names, call counts, host-side durations, and total profiled wall time. rank_operators() validates and orders those records without assigning a GPU bottleneck from host time alone.

Read the recorded operator profile

Download the lab from this page, extract it, and run these commands from its directory. The default command reads saved run records or runs the explicitly described local algorithm; it never downloads a model or calls a paid API.

Run the local analysis and checksTerminal · bash
python3 lab.py
python3 -m unittest -v test_lab.py
Read lab.py
lab.pySource · pythonDownload
"""Rank actual host operator records without inferring GPU utilization."""

import json, math
from pathlib import Path


def rank_operators(rows):
    if not rows:
        raise ValueError("Operator records are required")
    if any(
        not math.isfinite(r["self_cpu_us"]) or r["self_cpu_us"] < 0 or r["calls"] < 1
        for r in rows
    ):
        raise ValueError("Invalid host operator record")
    return sorted(rows, key=lambda r: r["self_cpu_us"], reverse=True)


def main():
    record = json.loads(Path("profile-run.json").read_text())
    print(
        json.dumps(
            {
                "execution_mode": "offline analysis of actual CPU profiler events around Metal model execution",
                "profiled_wall_ms": record["profiled_wall_ms"],
                "top_host_operators": rank_operators(record["operators"]),
                "limits": "Host operator time is not GPU kernel time, GPU utilization or device bandwidth. Profiling changes execution.",
            },
            indent=2,
        )
    )


if __name__ == "__main__":
    main()
Read profile_live.py
profile_live.pySource · pythonDownload
"""Collect actual CPU operator events around synchronized local model forwards on Metal."""

import argparse
import hashlib
import json
import platform
import time
from pathlib import Path


def main():
    p = argparse.ArgumentParser()
    p.add_argument("--model-path", required=True)
    p.add_argument("--output", required=True)
    a = p.parse_args()
    import torch, transformers
    from transformers import AutoTokenizer, AutoModelForCausalLM

    tokenizer = AutoTokenizer.from_pretrained(a.model_path, local_files_only=True)
    model = (
        AutoModelForCausalLM.from_pretrained(
            a.model_path,
            local_files_only=True,
            dtype=torch.float32,
            attn_implementation="eager",
        )
        .eval()
        .to("mps")
    )
    ids = tokenizer(
        "A code assistant retrieves relevant functions before generating a patch.",
        return_tensors="pt",
    )["input_ids"].to("mps")
    with torch.inference_mode():
        model(ids, use_cache=True)
    torch.mps.synchronize()
    start = time.perf_counter()
    with torch.profiler.profile(
        activities=[torch.profiler.ProfilerActivity.CPU], record_shapes=True
    ) as prof:
        with torch.inference_mode():
            result = model(ids, use_cache=True)
            torch.mps.synchronize()
    elapsed = (time.perf_counter() - start) * 1000
    rows = sorted(
        prof.key_averages(), key=lambda x: x.self_cpu_time_total, reverse=True
    )[:12]
    result = {
        "execution_mode": "fresh local inference; CPU operator profiler around Metal execution",
        "environment": {
            "torch": torch.__version__,
            "transformers": transformers.__version__,
            "platform": platform.platform(),
            "python": platform.python_version(),
        },
        "model_id": "Qwen/Qwen2.5-0.5B-Instruct",
        "model_revision": "7ae557604adf67be50417f59c2c2f167def9a775",
        "source_sha256": hashlib.sha256(Path(__file__).read_bytes()).hexdigest(),
        "profiled_wall_ms": round(elapsed, 3),
        "operators": [
            {
                "name": x.key,
                "calls": x.count,
                "self_cpu_us": round(x.self_cpu_time_total, 3),
            }
            for x in rows
        ],
        "limits": "CPU operator durations include dispatch and synchronization overhead, not GPU kernel duration or occupancy. Profiling changes runtime; compare unprofiled repetitions separately.",
    }
    Path(a.output).write_text(json.dumps(result, indent=2) + "\n")


if __name__ == "__main__":
    main()

The actual operator records identify where to investigate host work. They cannot establish GPU occupancy or kernel bandwidth. Keep the profiled wall time separate from unprofiled latency because instrumentation changes execution.

Inspect the complete local result
Recorded local resultRecorded output · jsonDownload
{
  "execution_mode": "offline analysis of actual CPU profiler events around Metal model execution",
  "profiled_wall_ms": 55.753,
  "top_host_operators": [
    {
      "name": "aten::linear",
      "calls": 169,
      "self_cpu_us": 3648.743
    },
    {
      "name": "aten::bmm",
      "calls": 48,
      "self_cpu_us": 1436.852
    },
    {
      "name": "aten::_softmax",
      "calls": 24,
      "self_cpu_us": 687.908
    },
    {
      "name": "aten::mul",
      "calls": 245,
      "self_cpu_us": 492.195
    },
    {
      "name": "aten::add",
      "calls": 172,
      "self_cpu_us": 386.367
    },
    {
      "name": "aten::copy_",
      "calls": 196,
      "self_cpu_us": 216.708
    },
    {
      "name": "aten::cat",
      "calls": 97,
      "self_cpu_us": 187.702
    },
    {
      "name": "aten::empty",
      "calls": 298,
      "self_cpu_us": 153.942
    },
    {
      "name": "aten::flatten",
      "calls": 338,
      "self_cpu_us": 124.089
    },
    {
      "name": "aten::matmul",
      "calls": 48,
      "self_cpu_us": 117.886
    },
    {
      "name": "aten::pow",
      "calls": 49,
      "self_cpu_us": 112.667
    },
    {
      "name": "aten::_to_copy",
      "calls": 124,
      "self_cpu_us": 106.667
    }
  ],
  "limits": "Host operator time is not GPU kernel time, GPU utilization or device bandwidth. Profiling changes execution."
}
Inspect the actual execution record
Actual execution recordRecorded output · jsonDownload
{
  "execution_mode": "fresh local inference; CPU operator profiler around Metal execution",
  "environment": {
    "torch": "2.14.1",
    "transformers": "5.20.2",
    "platform": "macOS-27.0.1-arm64-arm-64bit",
    "python": "3.12.8"
  },
  "model_id": "Qwen/Qwen2.5-0.5B-Instruct",
  "model_revision": "7ae557604adf67be50417f59c2c2f167def9a775",
  "source_sha256": "f09d10cf253f5c7cc013997835f56d5aced87588786efa1e575bef4bc04334da",
  "profiled_wall_ms": 55.753,
  "operators": [
    {
      "name": "aten::linear",
      "calls": 169,
      "self_cpu_us": 3648.743
    },
    {
      "name": "aten::bmm",
      "calls": 48,
      "self_cpu_us": 1436.852
    },
    {
      "name": "aten::_softmax",
      "calls": 24,
      "self_cpu_us": 687.908
    },
    {
      "name": "aten::mul",
      "calls": 245,
      "self_cpu_us": 492.195
    },
    {
      "name": "aten::add",
      "calls": 172,
      "self_cpu_us": 386.367
    },
    {
      "name": "aten::copy_",
      "calls": 196,
      "self_cpu_us": 216.708
    },
    {
      "name": "aten::cat",
      "calls": 97,
      "self_cpu_us": 187.702
    },
    {
      "name": "aten::empty",
      "calls": 298,
      "self_cpu_us": 153.942
    },
    {
      "name": "aten::flatten",
      "calls": 338,
      "self_cpu_us": 124.089
    },
    {
      "name": "aten::matmul",
      "calls": 48,
      "self_cpu_us": 117.886
    },
    {
      "name": "aten::pow",
      "calls": 49,
      "self_cpu_us": 112.667
    },
    {
      "name": "aten::_to_copy",
      "calls": 124,
      "self_cpu_us": 106.667
    }
  ],
  "limits": "CPU operator durations include dispatch and synchronization overhead, not GPU kernel duration or occupancy. Profiling changes runtime; compare unprofiled repetitions separately."
}
Saved output report for investigate host overhead before changing gpu settings; execution mode and values come from the linked raw result.

This image is an application-generated report of the saved program result, not a new inference run. Open the full-resolution report or read the raw result.

Distinguish host overhead from device work

Profiling adds overhead and can alter execution. Moving tokenization into a worker pool may improve request overlap but add coordination costs. Capturing a CUDA graph can reduce repeated launch overhead on a supported NVIDIA runtime, but it does not fix every memory or scheduling bottleneck and was not executed here.

Missing operator records. An empty profile is rejected instead of returning a confident diagnosis with no observed events.

Invalid host duration. Negative or nonfinite operator durations fail validation. A valid host event still cannot be interpreted as a GPU kernel measurement.

Read the executable checks
Executable checksSource · pythonDownload
import unittest
from lab import rank_operators


class ProfileTests(unittest.TestCase):
    def test_rank_uses_actual_host_duration(self):
        rows = [
            {"name": "b", "calls": 2, "self_cpu_us": 3},
            {"name": "a", "calls": 1, "self_cpu_us": 7},
        ]
        self.assertEqual(rank_operators(rows)[0]["name"], "a")

    def test_empty_profile_is_rejected(self):
        with self.assertRaises(ValueError):
            rank_operators([])

    def test_nonfinite_duration_is_rejected(self):
        for value in [float("nan"), float("inf"), -1]:
            with self.assertRaises(ValueError):
                rank_operators([{"name": "a", "calls": 1, "self_cpu_us": value}])


if __name__ == "__main__":
    unittest.main()

Use the pinned live runtime from the first lesson for model commands. A path placeholder refers to your explicitly downloaded model; these commands do not fetch one automatically.

Run the live implementationTerminal · bash
python3 -m venv .venv
.venv/bin/python -m pip install -r requirements-live.txt
.venv/bin/python profile_live.py --model-path /path/to/downloaded/model --output new-profile-run.json

Try a change and explain the result

Inspect the real top host-side operators. Identify what additional device trace would be needed before calling one a GPU bottleneck. Repeat a focused profile after one implementation change, then compare unprofiled latency separately.

A CPU profiler reports a slow operator around Metal work. What does that establish?

Choose one answer, then check your reasoning.

Read the explanation

Host operator events describe host-side work. Device kernel duration and utilization need appropriate device profiling.

Validate one change at a time

Start with an unprofiled baseline, collect a focused profile, change one cause, then repeat the baseline. Use Nsight Systems for NVIDIA timelines and Nsight Compute for selected kernels. Do not infer a whole-model speedup from a single utilization metric.

References

Sources checked October 24, 2026. Runtime-specific commands and results apply to the recorded versions; linked rolling documentation can change. The application scenarios are teaching examples, not claims about an author’s production incident.

Written by Arjun Prabhulal.

Module 5

Debug slow GPUs and tail latency