Edit

Share via


Debug high CPU usage in .NET Core

This article applies to: ✔️ .NET Core 3.1 SDK and later versions

In this tutorial, you'll learn how to debug an excessive CPU usage scenario. Using the provided example ASP.NET Core web app source code repository, you can cause a deadlock intentionally. The endpoint will stop responding and experience thread accumulation. You'll learn how you can use various tools to diagnose this scenario with several key pieces of diagnostics data.

In this tutorial, you will:

  • Investigate high CPU usage
  • Determine CPU usage with dotnet-counters
  • Use dotnet-trace for trace generation
  • Profile performance in PerfView
  • Diagnose and solve excessive CPU usage

Prerequisites

The tutorial uses:

CPU counters

Before attempting this tutorial, please install the latest version of dotnet-counters:

dotnet tool install --global dotnet-counters

If your app is running a version of .NET older than .NET 9, the output UI of dotnet-counters will look slightly different; see dotnet-counters for details.

Before attempting to collect diagnostics data, you need to observe a high CPU condition. Run the sample application using the following command from the project root directory.

dotnet run

To check the current CPU usage, use the dotnet-counters tool command:

dotnet-counters monitor -n DiagnosticScenarios --showDeltas

The output should be similar to the following:

Press p to pause, r to resume, q to quit.
    Status: Running

Name                                                            Current Value      Last Delta
[System.Runtime]
    dotnet.assembly.count ({assembly})                               111               0
    dotnet.gc.collections ({collection})
        gc.heap.generation
        ------------------
        gen0                                                           8               0
        gen1                                                           1               0
        gen2                                                           0               0
    dotnet.gc.heap.total_allocated (By)                        4,042,656          24,512
    dotnet.gc.last_collection.heap.fragmentation.size (By)
        gc.heap.generation
        ------------------
        gen0                                                     801,728               0
        gen1                                                       6,048               0
        gen2                                                           0               0
        loh                                                            0               0
        poh                                                            0               0
    dotnet.gc.last_collection.heap.size (By)
        gc.heap.generation
        ------------------
        gen0                                                     811,512               0
        gen1                                                     562,024               0
        gen2                                                   1,095,056               0
        loh                                                       98,384               0
        poh                                                       24,528               0
    dotnet.gc.last_collection.memory.committed_size (By)       5,623,808               0
    dotnet.gc.pause.time (s)                                           0.019           0
    dotnet.jit.compilation.time (s)                                    0.582           0
    dotnet.jit.compiled_il.size (By)                             138,895               0
    dotnet.jit.compiled_methods ({method})                         1,470               0
    dotnet.monitor.lock_contentions ({contention})                     4               0
    dotnet.process.cpu.count ({cpu})                                  22               0
    dotnet.process.cpu.time (s)
        cpu.mode
        --------
        system                                                         0.109           0
        user                                                           0.453           0
    dotnet.process.memory.working_set (By)                    65,515,520               0
    dotnet.thread_pool.queue.length ({work_item})                      0               0
    dotnet.thread_pool.thread.count ({thread})                         0               0
    dotnet.thread_pool.work_item.count ({work_item})                   6               0
    dotnet.timer.count ({timer})                                       0               0

Focusing in on the Last Delta values of dotnet.process.cpu.time, these tell us how many seconds within the refresh period (currently set to the default of 1 s) the CPU has been active. With the web app running, immediately after startup, the CPU isn't being consumed at all and these deltas are both 0. Navigate to the api/diagscenario/highcpu route with 60000 as the route parameter:

https://localhost:5001/api/diagscenario/highcpu/60000

Now, rerun the dotnet-counters command.

dotnet-counters monitor -n DiagnosticScenarios --showDeltas

You should see an increase in CPU usage as shown below (depending on the host machine, expect varying CPU usage):

Press p to pause, r to resume, q to quit.
    Status: Running

Name                                                            Current Value      Last Delta
[System.Runtime]
    dotnet.assembly.count ({assembly})                               111               0
    dotnet.gc.collections ({collection})
        gc.heap.generation
        ------------------
        gen0                                                           8               0
        gen1                                                           1               0
        gen2                                                           0               0
    dotnet.gc.heap.total_allocated (By)                        4,042,656          24,512
    dotnet.gc.last_collection.heap.fragmentation.size (By)
        gc.heap.generation
        ------------------
        gen0                                                     801,728               0
        gen1                                                       6,048               0
        gen2                                                           0               0
        loh                                                            0               0
        poh                                                            0               0
    dotnet.gc.last_collection.heap.size (By)
        gc.heap.generation
        ------------------
        gen0                                                     811,512               0
        gen1                                                     562,024               0
        gen2                                                   1,095,056               0
        loh                                                       98,384               0
        poh                                                       24,528               0
    dotnet.gc.last_collection.memory.committed_size (By)       5,623,808               0
    dotnet.gc.pause.time (s)                                           0.019           0
    dotnet.jit.compilation.time (s)                                    0.582           0
    dotnet.jit.compiled_il.size (By)                             138,895               0
    dotnet.jit.compiled_methods ({method})                         1,470               0
    dotnet.monitor.lock_contentions ({contention})                     4               0
    dotnet.process.cpu.count ({cpu})                                  22               0
    dotnet.process.cpu.time (s)
        cpu.mode
        --------
        system                                                         0.344           0.013
        user                                                          14.203           0.963
    dotnet.process.memory.working_set (By)                    65,515,520               0
    dotnet.thread_pool.queue.length ({work_item})                      0               0
    dotnet.thread_pool.thread.count ({thread})                         0               0
    dotnet.thread_pool.work_item.count ({work_item})                   6               0
    dotnet.timer.count ({timer})                                       0               0

Throughout the duration of the request, the CPU usage will hover around the increased value.

Tip

To visualize an even higher CPU usage, you can exercise this endpoint in multiple browser tabs simultaneously.

At this point, you can safely say the CPU is running higher than you expect. Identifying the effects of a problem is key to finding the cause. We will use the effect of high CPU consumption in addition to diagnostic tools to find the cause of the problem.

Analyze High CPU with Profiler

When analyzing an app with high CPU usage, you need a diagnostics tool that can provide insights into what the code is doing. The usual choice is a profiler, and there are different profiler options to choose from. dotnet-trace can be used on all operating systems, however, its limitations of safe-point bias and managed-only callstacks result in more general information compared to a kernel-aware profiler like 'perf' for Linux or ETW for Windows. If your performance investigation involves only managed code, generally dotnet-trace will be sufficient.

The perf tool can be used to generate .NET Core app profiles. We will demonstrate this tool, although dotnet-trace could be used as well. Exit the previous instance of the sample debug target.

Set the DOTNET_PerfMapEnabled environment variable to cause the .NET app to create a map file in the /tmp directory. This map file is used by perf to map CPU addresses to JIT-generated functions by name. For more information, see Export perf maps and jit dumps.

Note

.NET 6 standardizes on the prefix DOTNET_ instead of COMPlus_ for environment variables that configure .NET run-time behavior. However, the COMPlus_ prefix will continue to work. If you're using a previous version of the .NET runtime, you should still use the COMPlus_ prefix for environment variables.

Run the sample debug target in the same terminal session.

export DOTNET_PerfMapEnabled=1
dotnet run

Exercise the high CPU API endpoint (https://localhost:5001/api/diagscenario/highcpu/60000) again. While it's running within the 1-minute request, run the perf command with your process ID:

sudo perf record -p 2266 -g

The perf command starts the performance collection process. Let it run for about 20-30 seconds, then press Ctrl+C to exit the collection process. You can use the same perf command to see the output of the trace.

sudo perf report -f

You can also generate a flame-graph by using the following commands:

git clone --depth=1 https://github.com/BrendanGregg/FlameGraph
sudo perf script | FlameGraph/stackcollapse-perf.pl | FlameGraph/flamegraph.pl > flamegraph.svg

This command generates a flamegraph.svg that you can view in the browser to investigate the performance problem:

Flame graph SVG image

Analyzing High CPU Data with Visual Studio

All *.nettrace files can be analyzed in Visual Studio. To analyze a Linux *.nettrace file in Visual Studio, transfer the *.nettrace file, in addition to the other necessary documents, to a Windows machine, and then open the *.nettrace file in Visual Studio. For more information, see Analyze CPU Usage Data.

See also

Next steps