首页 > 其他分享 >使用火焰图分析.NET的 start-up 期间花费的时间

使用火焰图分析.NET的 start-up 期间花费的时间

时间:2023-07-01 10:35:22浏览次数:51  
标签:毫秒 PerfView up coreclr start hostpolicy CorHost2 NET

本文将告诉你从“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 是一个非常强大的程序,但不是最易于使用的工具,因此我写了一个逐步指南:
  1. 下载并运行最新版本的'PerfView.exe'
  2. 点击“Run a command(运行命令)”或(Alt-R)并选择“collect data while the command is running(在命令运行时收集数据)”
  3. 确保已输入以下值:
    1. “Command”(命令)
    2. “Current Dir”(当前目录)
  4. 如果尚未选中“Cpu Samples(CPU采样)”,那请选中它,确保这选项是打勾的
  5. 将“Max Collect Sec(最长收集时间)”设置为15秒(因为我们的“HelloWorld”应用程序永远不会退出,我们需要确保PerfView在某个时刻停止收集数据)
  6. 确保选择了“.NET Symbol Collection(.NET符号收集)”
  7. 点击“Run Command(运行命令)”
然后,如果您检查日志,您会看到它正在收集数据,获取符号,然后最终将所有内容写入一个.zip文件。完成后,您应该在主界面的左侧窗格中看到新创建的文件,本例中称为“PerfViewData.etl.zip”。

数据处理

一旦你有了“.etl.zip”文件,双击它,您将看到一个树视图,显示所有可用的数据。现在,选择“CPU Stacks”,您将看到以下视图: 注意列表中有很多“?”字符,这意味着PerfView无法解析运行时dll所需的方法名称。让我们修复这个问题:
  1. 打开“CPU Stacks”
  2. 在列表中,选择“HelloWorld”进程(PerfView在整个机器上收集数据)
  3. 在“GroupPats”下拉菜单中,选择“[no grouping]”
  4. 可选项,将“Symbol Path”从默认值更改为其他值
  5. 在“By name”选项卡中,按下“Ctrl+A”选择所有行
  6. 右键单击并选择“Lookup Symbols”(或按下“Alt+S”)
  现在,“CPU Stacks”视图应该类似于以下内容: 最后,我们可以获得我们想要的数据:
  1. 选择“Flame Graph”选项卡
  2. 将“GroupPats”更改为以下选项之一,以获得更好的火焰图:
    1. [group module entries] {%}!=>module $1
    2. [group class entries] {%!*}.%(=>class $1;{%!*}::=>class $1
  3. 将“Fold%”更改为更高的数字,例如3%,以去除那些细小的条(过高的数字会导致丢失信息)
  现在,我实际上建议将PerfView数据导出为可以加载到 https://speedscope.app/ 中的格式,因为它可以提供更好的体验。要做到这一点,请单击“文件”->“另存为视图”,然后在“另存为类型”框中选择“Speed Scope Format”。完成后,你可以在speedscope.app上“浏览”该文件。   注意:如果你以前从了解到过“火焰图”,我强烈建议阅读 Julia Evans 关于 perf & flamegraphs 的精彩解释: 分析性能数据的 3 种方法

分析.NET Runtime的Startup

最后,我们可以回答最初的问题: .NET Runtime在启动期间花费时间较多的地方是哪里? 以下是火焰图中汇总为文本的数据,其中包含“.NET Core Runtime”源代码中相应函数的链接:
  1. 整个应用程序 - 100% - 233.28毫秒
  2. 除了helloworld!wmain之外的所有内容 - 21%
  3. helloworld!wmain - 79% - 184.57毫秒
    1. hostpolicy!create_hostpolicy_context - 30% - 70.92毫秒(create_hostpolicy_context函数
    2. hostpolicy!create_coreclr - 22% - 50.51毫秒(create_coreclr 函数
      1. coreclr!CorHost2::Start - 9% - 20.98毫秒(CorHost2::Start 函数
      2. coreclr!CorHost2::CreateAppDomain - 10% - 23.52毫秒(CorHost2::CreateAppDomain 函数
    3. hostpolicy!runapp - 20% - 46.20毫秒(runapp 函数),最终调用Assembly::ExecuteMainMethodAssembly::ExecuteMainMethod 函数
      1. coreclr!RunMain - 9.9% - 23.12毫秒(RunMain 函数
      2. coreclr!RunStartupHooks - 8.1% - 19.00毫秒(RunStartupHooks 函数
    4. hostfxr!resolve_frameworks_for_app - 3.4% - 7.89毫秒(fx_resolver_t::resolve_frameworks_for_app 函数
  因此,运行时花费时间最多的地方是:
  1. 30%的总时间用于启动runtime,由“host policy”控制,其中大部分发生在hostpolicy!create_hostpolicy_context中(总时间的30%)
  2. 22%的时间用于初始化runtime本身以及它创建的初始(也是唯一的)AppDomain,这可以在CorHost2::Start(native 本地)和CorHost2::CreateAppDomain(managed 托管)中看到。有关这方面的更多信息,请参阅CLR在执行一行代码之前所做的68件事情
  3. 20%用于 JIT编译和执行 “Hello World”代码示例中的Main方法,这是从上面的Assembly::ExecuteMainMethod中开始的。
为了确认最后一点,我们可以返回到 PerfView 并查看它生成的“JIT Stats Summary(JIT统计摘要)”。从主菜单的“Advanced Group”->“JIT Stats”下,我们可以看到23.1毫秒或总CPU时间的9.1%花在了JIT编译上。  

标签:毫秒,PerfView,up,coreclr,start,hostpolicy,CorHost2,NET
From: https://www.cnblogs.com/wxlevel/p/17518917.html

相关文章

  • 记一次 .NET 某埋线管理系统 崩溃分析
    一:背景1.讲故事经常有朋友跟我反馈,说看你的文章就像看天书一样,有没有一些简单入手的dump让我们先找找感觉,哈哈,今天就给大家带来一篇入门级的案例,这里的入门是从WinDbg的角度来阐述的,这个问题如果你通过记日志,分析代码的方式,可能真的无法解决,不信的话继续往下看呗!前段时间有位......
  • Linux 上的 .NET 如何自主生成 Dump
    一:背景1.讲故事前几天微信上有位朋友找到我,说他程序的线程数会偶发性瞬时飙高,让我看下大概是什么原因,截图如下:如果这种问题每天都会出现,比较好的做法就是用dotnet-trace捕获ThreadCreated事件,但可气的是朋友说大概一个月发生次把,这种情况下用dotnet-trace持续监视就没必要......
  • MySQL批量新增或修改时出现异常: Lock wait timeout exceeded; try restarting transact
    标题:解决MySQL批量新增或修改时出现"nestedexceptionisjava.sql.SQLException:Lockwaittimeoutexceeded;tryrestartingtransaction"异常摘要在使用MySQL数据库进行批量新增或修改操作时,有时候会遇到"nestedexceptionisjava.sql.SQLException:Lockwaittimeoutexcee......
  • [问题记录] com.netflix.hystrix.exception.HystrixRuntimeException timed-out and n
    报错描述服务重启后第一次访问调用Feign接口会503,走熔断器的fallback打一次断点后再访问就没有问题,服务重启后第一次访问打断点也是503解决方案Hystrix缺省超时判断为1秒钟,由于网络问题,有些请求超过1秒钟之后才接收到增加响应时间即可hystrix:command:defau......
  • .NET 7 新特性全面解析
    在2021年11月8日发布的.NET6当前已经广泛使用。微软团队已经开始着手为.NET7制定计划和新特性。本文将为您全面解析.NET7的新特性,并提供源代码示例。1.更好的性能.NET7将继续提高运行时性能,改进JIT编译器,减少内存分配,优化GC,以及提高ASP.NETCore和EntityF......
  • oracle startup命令及lsnrctl命令
    启动一个数据库需要三个步骤:1、创建一个Oracle实例(非安装阶段)2、由实例安装数据库(安装阶段)3、打开数据库(打开阶段)在Startup 命令中,可以通过不同的选项来控制数据库的不同启动步骤。  Oracle数据库的完整启动过程分为3个步骤完成的启动实例–>加载数据库–>打开数据库;数......
  • Net6 中一个请求用到的
    Microsoft.AspNetCore.Hosting.HttpRequestIn.StartMicrosoft.AspNetCore.Hosting.BeginRequestMicrosoft.AspNetCore.Routing.EndpointMatched 终结点匹配Microsoft.AspNetCore.Mvc.BeforeOnActionExecuting--动作执行前Microsoft.AspNetCore.Mvc.AfterOnActionExecuting......
  • 15.面向对象和super
    面向对象和super()类(Class):具有相同的属性和方法的对象的集合,即定义对象的模板对象(Object):类的实例化对象,有自己的属性和方法。类方法:使用装饰器@classmethod,传递类的属性和方法(不能传实例的属性和方法)类属性:类中的变量。类变量在整个实例化的对象中是公用的实例......
  • The Open Group与机械工业出版社达成战略签约暨TOGAF®标准第10版中文图书预发布!
     6月29日,由TheOpenGroup主办的「2023架构·可持续未来峰会」如期拉开帷幕。 现场,TheOpenGroup与机械工业出版社正式举行了战略合作签约仪式,并就TOGAF®标准第10版中文版图书预发布,以及OPA标准2.1版的本地化工作展开具体合作(点击项目名称即可提交意向登记)。 战略签约 长久共......
  • kubernetes学习笔记06(存储)
    Kubernetes存储管理容器中的磁盘生命周期是短暂的,也带来了一系列的问题:当一个容器损坏后,Kubernetes会重启容器,但是文件会丢失很多容器在同一Pod中运行的时候,数据文件需要共享KubernetesVolume的到来解决了上述问题,Kubernetes集群中的存储跟Docker的存储卷有些类似,只不过Docker的存......