Skip to main content

Reading a Profiler trace without guessing

Note: this is part 3 of a series on the Azure Monitor Profiler. Part 1 covered what the Profiler is, part 2 covered enabling it. This post is about the part that actually matters: making sense of a trace once you have one.

Having profiler traces is only half the job. I've seen people enable the profiler, open a trace, stare at a wall of unfamiliar method names, and close the tab. The trace explorer isn't self-explanatory the first time - it took me a few real incidents before the views clicked. This post is the walkthrough I wish I'd had.

Getting to a trace

From your Application Insights resource:

  • Go to the Performance tab

  • Pick an operation from the list or leave Overall selected

  • Click on Profiler traces 

  • Pick one of the captured requests, ideally one with a longer duration than usual - that's where you'll actually find something.

Once you're in a trace, you get two views of the same call stack data:

  • Flame graph - the full call stack hierarchy, rendered as stacked bars. Wider bars mean more time spent in that call. This is the shape most people recognize.

  • Profile tree - the same information as an expandable tree instead of a graph. Sometimes easier to scan when you're hunting for a specific method name rather than a visual hot spot.




    Neither view is "more correct" - use whichever matches how you think about the problem.

    Start with Hot path, not the top of the tree

    Don't start reading top-down. Select Hot path, and the explorer jumps straight to the biggest leaf node - in most cases, that's the actual bottleneck. This is the single most useful feature in the whole tool, and it's activated by default.

    Once you're at the hot path, the columns tell the rest of the story:

    • Event - the function or event name. You'll see a mix of your own code and framework/dependency events like SQL or HTTP calls.
    • Module - where that event or function lives.
    • Thread time - the interval between the start and end of the operation.
    • Timeline / When - a visual histogram of samples across the request's duration, split into 32 buckets. A tall bar means the node was actively consuming a resource in that slice of time.

    Learning the vocabulary

    The label on the hot node tells you what kind of bottleneck you're looking at, and the labels aren't always obvious the first time you see them:

    • CPU time - straightforward: the CPU is busy executing your instructions. This is genuine compute cost.
    • AWAIT_TIME - your code hit an await and is logically blocked waiting for a task to finish, even though no thread is actually parked waiting for it. If AWAIT_TIME shows up inside framework code rather than your own, it's usually the plumbing around the await (or telemetry recording it) rather than a real clue - toggle off Framework dependencies at the top of the page to filter that noise out and see only your code.
    • BLOCKED_TIME - the code is waiting on some other resource: a sync object, an available thread, a request to finish.
    • clr!JITutil_MonContention / clr!JITutil_MonEnterWorker - lock contention. One thread's holding a lock (a lock statement, Monitor.Enter, a [MethodImpl(MethodImplOptions.Synchronized)] method) and another's waiting on it.
    • clr!JIT_New / clr!JIT_Newarr1 - object or array allocation. These are normally fast; if either is eating noticeable time, you're likely allocating heavily somewhere nearby.
    • clr!ThePreStub or a method tagged [COLD] - JIT compilation cost or unoptimized code running for the first time in the process. Should only show up once per method per process - if it's showing up on a request your users are hitting, a warmup routine that exercises that code path before traffic arrives is the fix.
    • Unmanaged Async - native code or older-style async that the Profiler can't track across threads via ETW. If you need more than the label, download the ETW file and open it in PerfView.

    Why is this important?

    Say your hot path leads to a node showing SqlCommand.Execute with a wide bar and high thread time. That's not CPU cost - it's your code waiting on a database round trip. Compare that to a hot path dominated by clr!JITutil_MonContention: same symptom on the outside (slow request), completely different fix. One is "optimize or cache the query," the other is "find out what else is holding that lock."

    That distinction is the entire point of reading the trace instead of guessing from the outside. A slow request and a slow request look identical from Application Insights' duration charts. They don't look identical in a flame graph.

    The profiler is a CPU sampling profiler at heart. For genuinely I/O-bound waits - a slow downstream dependency, a database that's the actual problem rather than your query - the flame graph gives you the "waiting" label but not much depth beyond it. Application Insights' Transaction Diagnostics / dependency tracking is the better tool for drilling into why a dependency call itself was slow.

    Remark: If method names in your trace show up as raw memory addresses instead of readable names, your build isn't publishing debug symbols (PDB files) where the Profiler can find them. Make sure your CI/CD pipeline publishes PDBs alongside your deployment. Without them, everything past this point is unreadable.

    From reading one trace to not having to read traces at all

    Everything above is a manual skill: you open a trace, hit Hot path, and reason through the labels yourself. That's fine for one incident, but it doesn't scale to "review every slow request my app produces."

    That's what Code Optimizations is for. It's an AI-based service that sits on top of the same Profiler data - it doesn't need anything new enabled, it just analyzes the traces your Profiler is already collecting - and surfaces CPU and memory bottlenecks automatically, without you opening a single trace yourself.

    You get to it from Investigate > Performance > Code Optimizations on your Application Insights resource, or via a consolidated overview page that rolls up insights across every subscription and Application Insights resource you have access to - useful if you're watching more than one app.

    Each insight gives you:

    • A description of the performance issue, with the affected call stack
    • A CPU or memory cost expressed as a share of the trace: for memory, the percentage of all allocations made within that trace; for CPU, a percentage of total available CPU time (e.g. a 10-second trace on a 4-core box gives you 40 CPU-seconds to work with, so an insight citing 5% is pointing at roughly 2 seconds)
    • A trend timeline showing how the issue's impact has moved over time
    • An AI-generated recommendation for fixing it

    Remark: if you see no insights at all, that's not necessarily a bad sign - it usually just means Code Optimizations hasn't spotted a bottleneck worth flagging yet. Keep checking back rather than assuming it's broken.

    More information

    Popular posts from this blog

    Podman– Command execution failed with exit code 125

    After updating WSL on one of the developer machines, Podman failed to work. When we took a look through Podman Desktop, we noticed that Podman had stopped running and returned the following error message: Error: Command execution failed with exit code 125 Here are the steps we tried to fix the issue: We started by running podman info to get some extra details on what could be wrong: >podman info OS: windows/amd64 provider: wsl version: 5.3.1 Cannot connect to Podman. Please verify your connection to the Linux system using `podman system connection list`, or try `podman machine init` and `podman machine start` to manage a new Linux VM Error: unable to connect to Podman socket: failed to connect: dial tcp 127.0.0.1:2655: connectex: No connection could be made because the target machine actively refused it. That makes sense as the podman VM was not running. Let’s check the VM: >podman machine list NAME         ...

    Cache stampede: when our cache turned against us

    While investigating some performance issues, we ran into an ASP.NET Core API that cached a fairly expensive aggregation query for 60 seconds. Under normal load, that was fine: one request rebuilds the cache, everyone else reads from it. Under peak load, dozens of requests would arrive in that same expiry window, all see a cache miss, and all fire the same expensive query in parallel. The database didn't like that. That was the moment when our caching layer stopped helping and started hurting. A burst of requests comes in at the same time, all miss the cache, and all go hammer the database or the downstream API at once. That's a cache stampede . The cache was supposed to protect our backend, and for a few hundred milliseconds it did the opposite. Why this happens IMemoryCache.GetOrCreate (and its async sibling) looks like it protects you, but it doesn't add any locking on its own. Look at the naive version: public async Task<Report> GetReportAsync(string key) ...

    A complex system designed from scratch never works

    A few years ago, I worked as an architect on a big mainframe rewrite. I still count it as one of my failures. Not because the technology was wrong, but because I couldn't convince the management team to simplify the approach. Years later, the organization is still struggling to get the new system up and running. I left the project at the time, because I couldn't put my name behind an approach that would take very long and cost a lot of money without a working system to show for it along the way. Gall’s Law That memory keeps coming back to me, because it's a textbook case of Gall's Law playing out in real life. Gall's Law , from John Gall's Systemantics , states it plainly: A complex system that works is invariably found to have evolved from a simple system that worked. A complex system designed from scratch never works, and it cannot be patched to make it work. You have to start over with a simple system that works. What does that mean in practice,...