前言

新建一個(gè)ASP.NET Core Web API項(xiàng)目，使用命令行方式啟動，連續(xù)發(fā)送多次請求。

從下圖的時(shí)間線可以發(fā)現(xiàn)，第一次執(zhí)行（116ms）比后面的（2ms）慢了很多:

在這100多ms中，Web API到底做了些什么？！

示例代碼

為了更好定位Web API執(zhí)行情況，示例Controller代碼如下：

[HttpGet] public?string?Get() {Thread.Sleep(10);var?now?=?DateTime.Now;while?((DateTime.Now?-?now).TotalMilliseconds?<?10){}var?result?=?HttpContext.TraceIdentifier;Thread.Sleep(10);return?result; }

• Thread.Sleep用于將框架代碼和業(yè)務(wù)執(zhí)行代碼執(zhí)行時(shí)間分開

• while循環(huán)用于延長業(yè)務(wù)執(zhí)行時(shí)間，方便找到業(yè)務(wù)代碼

PerfView

PerfView是一款免費(fèi)的性能分析工具，可幫助排查CPU和內(nèi)存相關(guān)的性能問題。

從https://github.com/Microsoft/perfview/releases下載最新版本PerfView并啟動。

配置

點(diǎn)擊主界面上的“Collect data machine wide”鏈接，打開收集數(shù)據(jù)窗口：

為了記錄所有操作，需要設(shè)置“CPU Sample Interval”為較小值（0.125）。

收集

• 使用命令行方式啟動Web API

• 點(diǎn)擊收集數(shù)據(jù)窗口的“Start Collection”按鈕

• 執(zhí)行Web API請求

• 再點(diǎn)擊“Stop Collection”按鈕。

收集完成后，會生成.etl.zip文件：

雙擊“CPU Stacks”，會打開“Select Process Window”（選擇進(jìn)程窗口），因?yàn)镻erfView實(shí)際收集了所有進(jìn)程的性能數(shù)據(jù)。

選擇Web API對應(yīng)的進(jìn)程，點(diǎn)擊“OK”按鈕。

火焰圖

在打開的窗口中選擇“Flame Graph”(火焰圖)選項(xiàng)卡,上方的“GroupPats”選擇“[group class entries] {%!}.%(=>class $1;{%!}::=>class $1”，可以看到如下效果：

火焰圖是用來展示CPU的調(diào)用棧的圖形：

• y軸表示調(diào)用棧，每一層都是一個(gè)函數(shù)。調(diào)用棧越深，火焰就越高，頂部就是正在執(zhí)行的函數(shù)，下方都是它的父函數(shù)。

• x軸表示每個(gè)函數(shù)相對執(zhí)行的時(shí)間長短。

speedscope

由于調(diào)用的函數(shù)較多，火焰圖并不能很清晰地反映。

這時(shí)，我們可以使用speedscope，一個(gè)交互式火焰圖可視化工具，幫助我們分析。

選擇菜單"File"->"Save View As"，文件類型選擇“speed scope”。

打開網(wǎng)站https://www.speedscope.app/，將剛才保存的文件導(dǎo)入，效果如下圖：

頂部是線程列表，下面是所選線程對應(yīng)的火焰圖，可以看到它的堆棧順序與PerfView相反，是從上到下的。

很容易定位到Web API執(zhí)行的線程，因?yàn)榭梢钥吹絋hread.Sleep留出的2段空白。

分析

圖中相同的顏色塊表示同一函數(shù)，我們只需要找到和業(yè)務(wù)代碼同一行顏色不同的位置，就表示處于不同方法調(diào)用中。

先看業(yè)務(wù)代碼執(zhí)行前，從上往下看，很快就定位到一個(gè)運(yùn)行時(shí)間較長的位置：

執(zhí)行的是Http1Connection.TryParseRequest方法，耗時(shí)11.85ms，可見重用連接是非常有必要的。

下面是找到的部分耗時(shí)比較大的方法：

• 執(zhí)行前

• • Microsoft.AspNetCore.Routing.Matching.DfaMatcherFactory.CreateMatcher - 22.73ms

  • Microsoft.AspNetCore.Mvc.Infrastructure.ActionInvokerFactory.CreateInvoker - 30.15ms

• 執(zhí)行后

• • Microsoft.AspNetCore.Mvc.Formatters.TextOutputFormatter.WriteAsync - 5.79ms

結(jié)論

后面請求快的原因也可以解釋了，比如重用Http連接，方法內(nèi)部緩存了結(jié)果（DfaMatcherFactory調(diào)用了DataSourceDependentCache），這也為提高我們自己程序的性能指明了思路。

PerfView + speedscope確實(shí)能夠幫助我們分析性能，理解代碼執(zhí)行情況。你還不趕快安排上！

如果你覺得這篇文章對你有所啟發(fā)，請關(guān)注我的個(gè)人公眾號”My IO“，記住我！

總結(jié)

以上是生活随笔為你收集整理的差距50倍！为什么Web API第一次执行这么慢？的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。