使用 dotTrace 分析 .NET Core 代码问题

0.背景

在项目开发之中,前期可能主要以保证任务完成为主,对于性能优化主要在于开发完成之后再来进行。可能在测试的时候发现部分接口的代码执行时间过长,但是又毫无头绪,这个时候你就需要性能分析工具来协助你排查问题了。

常规性能分析借助于 Visual Studio 强大的性能测试工具就可以进行分析,但是这些功能只包含在企业版当中。这个时候我们就可以使用 JetBrains 的 .NET 分析全家桶来进行这个操作了,其包含内存分析(dotMemory)与性能分析(dotTrace),其实他的 dotCover(单元测试) 也是挺好用的。

1.安装与下载

1.1 下载

安装步骤较为简单,前往 Jetbrains 官网,找到 dotTrace ,点击下载即可。

其地址为 https://www.jetbrains.com/profiler/download/ ,选择自己需要的安装包形式,一般选择 WebInstaller 进行安装,当然这里推荐选择 Standalone (独立版),直接下载运行就 OK 。

1.2 安装

每个用户可以免费评估使用 10 天,当然你要使用某些补丁或者激活工具也是可以的,这里不再详述过程,只是注意一下(WebInstaller)在安装的时候选择自己需要的安装就可以了,不需要的直接选为 Skip 跳过。

1538107915198

你也可以在安装的时候选择 "Visual Studio Integration",这样就会与 VS 集成,在分析代码的时候可以快速跳转到相应的代码行。

1538104322568

2.使用与分析

dotTrace 使用比较方便,本身支持 .NET Core 分析,分析时只是会有四种不同的分析模式,这里大概讲解一下各种分析模式的区别。

1538108158793

Profiler Options 作用与描述
Sampling 通过获取 CLR 内部一个方法开始执行和结束执行的时间差来计算的分析时间。
这是最快的方法,它用于精确测量程序运行时间,但可能会丢失一些数据。
使用此配置类型可使你快速获取应用程序的的总体性能。
Tracing 慢于 Sampling 的方法,但是可以准确地测量特定方法被调用的准确次数。
它是通过获取 CLR 内部一个方法开始执行和结束执行的时间差来计算的分
析时间。
Line-by-line 通过收集代码执行的每条语句的时间来进行比较,它计算出的时间更加精确。
该方法适用于你已经知道性能问题大概在哪里出现,并要找到具体某一个出
现性能问题的时候。
Timeline 采取抽样的方式,每隔一段时间 (10 ms),会暂停所有线程,并抓取堆栈里的
信息,然后才计算出代码执行时间差。使用这个方式可能会导致一些执行时间
少于 10 ms 的方法无法被抓取到。

一般来说我们使用的是 Tracing 来进行代码的性能分析,因为一般都是需要查看每个方法具体的调用时间。下面我就将以一个接口的实例来作为示范,看如何来排查调用缓慢的问题。

2.1 获取快照信息

首先运行 dotTrace 之后,选择 .NET Core Application,之后右侧的 Profiler Options 则选择 Tracing。最后一步则是选择需要进行检测的 dll 文件,这里我选择的是一个基于 Abp 框架开发的 ASP.NET Core 项目。

1538112730246

当然,你也可以勾选上 Advanced ,配置诸如启动参数之类的东西,之后点击 Run 则开始进行分析了。

1538113236471

这里右下角的 Get Snapshot and Wait 点击之后呢,就会获取到快照文件了,当然现在先不慌,我们先来测试一下我们要测试的接口。

比如说我这里有一个 TestMethod 方法,其代码如下:

public class TestApplicationService : ApplicationService
{
    private readonly IRepository<SysSystem> _tempRep;

    public TestApplicationService(IRepository<SysSystem> tempRep)
    {
        _tempRep = tempRep;
    }

    public async Task<string> TestMethod()
    {
        var systems = _tempRep.GetAll().ToList();

        foreach (var system in systems)
        {
            system.Status = 10;
            await _tempRep.UpdateAsync(system);
        }

        int i = 0;
        for (int j = 0; j < 10000; j++)
        {
            i += j;
        }

        return systems[0].SystemCode;
    }
}

现在我们通过 SwaggerUI 调用这个接口,看需要多长时间。

1538115114617

可以看到平均时常都需要 300ms ,现在我们点击 GetSnapshot and Wait 按钮,会弹出分析窗口,并且我们随时可以通过再次点击 Start 按钮,继续分析。

1538115225913

2.2 分析代码

2.2.1 概览信息

Tracing 分析的界面比较简单,一个 All Calls 页签与 Overview (概览) 的页签,首先我们大致看一下概览窗口。

1538115794174

可以看到他给我们标识了用户代码执行周期最长的一些地方,其次也用柱状图很直观地体现了耗时最长的代码分类。

右侧则提列了一些快照的信息与运行时的环境信息,以便用户作为参考。

2.2.2 Threads Tree (线程信息)

本窗口主要的作用是分析应用程序里面发生的所有的线程活动,主线程有一个 1538116056600 图标,而终结器线程则是拥有一个 1538116096937 图标,剩下的都是线程池内部的工作线程。

在这里我们以主线程为例,分析一下其具体内容所表达的意思。

1538116543296

  • Main:代表不带命名空间的方法简称。
  • 99 . 99 %:代表该方法针对于整个线程运行时间所占的百分比,这里的意思就是 Main 方法占用了整个主线程运行时间的 99.99 %。
  • 523,732 ms:代表该方法与子方法执行的总时间。
  • 1 call:方法在堆栈上所被调用的次数。
  • XXX.Web.Host.Startup.Program.Main(string[] ):被调用方法的全称,

2.2.3 Call Tree (调用树)

一般我们使用本页面的时候会多一点,这个页面会显示在所有线程中的所有被调用的方法。其每一个根节点代表的是每一个线程所执行的一个根函数,而下面每一个节点则代表其根函数内部调用的子函数的相关性能分析信息。

1538116689852

那么我们如何快速定位我们刚才测试的接口呢?

按下 Ctrl+F ,会弹出搜索框,在里面输入我们所编写的接口方法名字,按下回车就会快速定位了。

1538116763977

之后我们会看到如下内容:

1538117069160

通过展开节点我们可以知道最耗费时间的方法,即为 GetAll 方法,当点击节点的时候,右侧也会定位到相应的代码位置。

这里可以看到整个 GetAll 方法使用了 1015ms 的时间,这是为什么呢?你可以看到在其右侧有一个 8 calls ,这个时间是 8 次调用总共所花费的时间。

右键节点,你可以通过 Properties 可以看到该方法的平均执行时间:

1538117214194

可以看到其自身只花费了 8.3 μs,说明真正执行缓慢的还在其更深层,这里就不再往里面跟了,如果需要更加详细的性能报告,可以不使用 Tracing 模式,而使用 Line-by-line 模式来进行分析。

2.2.4 Plain List (简单列表)

以平铺的方式展示所有被调用过的方法列表,让你分析具体代码。

1538117794931

2.2.5 Hot Spots (热点跟踪)

该视图会列举出所有耗时最长的方法。

3.参考资料

CSDN:https://blog.csdn.net/weixin_38208401/article/details/75645021