本文将告诉你从“dotnet run”到“hello world”,如何使用 PerfView 来分析 .NET 运行时在启动期间所花费的时间。
代码示例
在这个示例中,我故意只关注.NET运行时在程序启动(start-up)过程中的操作,以确保运行的用户代码最少,因此只有以下的“Hello World”:using System;
namespace HelloWorld {
class Program {
static void Main(string[]args) {
Console.WriteLine("Hello World!");
Console.WriteLine("Press <ENTER> to exit");
Console.ReadLine();
}
}
}
添加Console.ReadLine()
是为了确保在 PerfView 仍在收集数据时进程不会退出。
数据收集
PerfView 是一个非常强大的程序,但不是最易于使用的工具,因此我写了一个逐步指南:- 下载并运行最新版本的'PerfView.exe'
- 点击“Run a command(运行命令)”或(Alt-R)并选择“collect data while the command is running(在命令运行时收集数据)”
-
确保已输入以下值:
- “Command”(命令)
- “Current Dir”(当前目录)
- 如果尚未选中“Cpu Samples(CPU采样)”,那请选中它,确保这选项是打勾的
- 将“Max Collect Sec(最长收集时间)”设置为15秒(因为我们的“HelloWorld”应用程序永远不会退出,我们需要确保PerfView在某个时刻停止收集数据)
- 确保选择了“.NET Symbol Collection(.NET符号收集)”
- 点击“Run Command(运行命令)”
数据处理
一旦你有了“.etl.zip”文件,双击它,您将看到一个树视图,显示所有可用的数据。现在,选择“CPU Stacks”,您将看到以下视图: 注意列表中有很多“?”字符,这意味着PerfView无法解析运行时dll所需的方法名称。让我们修复这个问题:- 打开“CPU Stacks”
- 在列表中,选择“HelloWorld”进程(PerfView在整个机器上收集数据)
- 在“GroupPats”下拉菜单中,选择“[no grouping]”
- 可选项,将“Symbol Path”从默认值更改为其他值
- 在“By name”选项卡中,按下“Ctrl+A”选择所有行
- 右键单击并选择“Lookup Symbols”(或按下“Alt+S”)
- 选择“Flame Graph”选项卡
-
将“GroupPats”更改为以下选项之一,以获得更好的火焰图:
- [group module entries] {%}!=>module $1
- [group class entries] {%!*}.%(=>class $1;{%!*}::=>class $1
- 将“Fold%”更改为更高的数字,例如3%,以去除那些细小的条(过高的数字会导致丢失信息)
分析.NET Runtime的Startup
最后,我们可以回答最初的问题: .NET Runtime在启动期间花费时间较多的地方是哪里? 以下是火焰图中汇总为文本的数据,其中包含“.NET Core Runtime”源代码中相应函数的链接:- 整个应用程序 - 100% - 233.28毫秒
- 除了
helloworld!wmain
之外的所有内容 - 21% -
helloworld!wmain
- 79% - 184.57毫秒hostpolicy!create_hostpolicy_context
- 30% - 70.92毫秒(create_hostpolicy_context函数)-
hostpolicy!create_coreclr
- 22% - 50.51毫秒(create_coreclr 函数coreclr!CorHost2::Start
- 9% - 20.98毫秒(CorHost2::Start 函数)coreclr!CorHost2::CreateAppDomain
- 10% - 23.52毫秒(CorHost2::CreateAppDomain 函数)
-
hostpolicy!runapp
- 20% - 46.20毫秒(runapp 函数),最终调用Assembly::ExecuteMainMethod
(Assembly::ExecuteMainMethod 函数)coreclr!RunMain
- 9.9% - 23.12毫秒(RunMain 函数)coreclr!RunStartupHooks
- 8.1% - 19.00毫秒(RunStartupHooks 函数)
hostfxr!resolve_frameworks_for_app
- 3.4% - 7.89毫秒(fx_resolver_t::resolve_frameworks_for_app 函数)
- 30%的总时间用于启动runtime,由“host policy”控制,其中大部分发生在
hostpolicy!create_hostpolicy_context
中(总时间的30%) - 22%的时间用于初始化runtime本身以及它创建的初始(也是唯一的)
AppDomain
,这可以在CorHost2::Start
(native 本地)和CorHost2::CreateAppDomain
(managed 托管)中看到。有关这方面的更多信息,请参阅CLR在执行一行代码之前所做的68件事情 - 20%用于 JIT编译和执行 “Hello World”代码示例中的
Main
方法,这是从上面的Assembly::ExecuteMainMethod
中开始的。