什么是 ASP.NET 应用程序中超过 65% 的时间消耗？答案

【问题标题】：What is consuming over 65% of time in an ASP.NET application?什么是 ASP.NET 应用程序中超过 65% 的时间消耗？
【发布时间】：2011-08-11 05:53:38
【问题描述】：

我有一个托管在 Windows 7 / IIS 7.5 上的 .Net Framework 4.0、ASP.NET、ASP.NET MVC 3 Web 应用程序。在这台机器上启用了 IIS 日志记录并设置为以 W3C 模式登录。

应用程序是使用 Release 配置编译的，并已部署到具有显式设置的 <compilation debug='false' 属性的 IIS。 Web.config 指定使用基于 SQL Server 的会话状态。

我在 Global.asax 中分别在 BeginRequest 和 EndRequest 事件中添加了以下语句。结果，即“sw.Elapsed.TotalMilliseconds”被存储在应用程序级别的值列表中。我通过调试页面转储这些值并获得相同的平均值。

// in BeginRequest
HttpContext.Current.Items.Add("RequestStartEnd", System.Diagnostics.Stopwatch.StartNew());

// in EndRequest
var sw = (System.Diagnostics.Stopwatch)HttpContext.Current.Items["RequestStartEnd"];
sw.Stop();

我创建了一个负载测试，它针对这个应用程序运行一个请求，并发用户负载为 20 个用户。测试在 Visual Studio 2010 Ultimate 版中运行。

运行负载测试后，我得到了秒表记录的平均耗时 681 毫秒。根据 IIS 对这些请求的平均耗时（我在运行负载测试之前清除了所有日志）是2121 毫秒。 IIS 所用的平均时间与 Visual Studio 负载测试报告中显示的值相符。

秒表所用时间仅占 IIS 日志/Visual Studio 报告的所用时间的 32%。剩下的 68% 时间去哪儿了？

更新 1： 我将会话状态设置为 InProc 并重新运行负载测试。在这种情况下，秒表报告的平均时间与 IIS 日志报告的平均所用时间之间的差异增长到 70% 以上！！！这么多时间都去哪儿了？

更新 2： @Peter - 我通过将跟踪规则设置为登录状态码 200 来尝试失败的请求跟踪。接下来，我对 20 个并发用户进行了大约 1.5 分钟的负载测试。查看最后 50 个跟踪文件，发现该报告中的“所用时间”字段的范围为 750 毫秒到 1300 毫秒。 Visual Studio 报告显示平均值。时间为2300ms。在报告中，使用紧凑视图，我看到以下转换之间的时间发生了变化 (1) AspNetStart -> AspNetAppDomainEnter (2) ManagedPipelineHandler-start ManagedPipelineHandler-end。 (2) 项可能是我的应用程序的代码。根据失败的请求日志（即 1300 毫秒）和平均所用时间之间仍然存在很大差异。 Visual Studio 2300ms 显示的耗时。如何找到会计？不过感谢这个很棒的提示！

【问题讨论】：

您应该考虑分析您的代码。与简单的基于秒表的性能计数器相比，它会为您提供更精细和更直接可用的数据。
@Merlyn - 我正在使用 Visual Studio 2010 Ultimate 分析器。将尝试查看打开“显示所有代码”的报告。但是，我怀疑问题可能出在 IIS 而不是 ASP.NET 中，因此可能不会包含在分析中。怀疑背后的原因是秒表计时是在 ASP.NET 的 request-start 和 request-end 事件中进行的。
您是否考虑过 ASP.NET 之外的系统级因素？例如IIS开销，网络？添加了更详细的答案。

标签： asp.net asp.net-mvc performance visual-studio-2010 iis-7.5

【解决方案1】：

您的负载测试运行了多长时间？如果您在 Windows 7 下运行它，您可能会得到与在 Windows 服务器下不同的结果。在突发负载下将线程分配给线程池时，您可能会遇到问题。 .Net 会立即将线程分配到线程池 min，然后慢慢分配到线程池 max。我相信客户端操作系统的默认设置与服务器操作系统的不同。它可能在客户端操作系统上，默认的最小线程设置等于您机器上的内核数，这意味着 .net 会慢慢分配更多线程以满足您的突发负载。

一个简单的检查是让您的负载测试运行更长时间，看看您的 2 个测量值之间的差距是否缩小。

【讨论】：

测试是在装有 IIS 7.5 的 Windows 7 机器上进行的。负载测试在 20 个用户的恒定负载下运行。我会尝试在同一台机器上运行更长的时间，然后会发回结果。
这里是关于如何更改 min/max worker/io 线程设置的信息。 msdn.microsoft.com/en-us/library/7w2sway1.aspx。需要注意的一个问题是您需要禁用自动配置，否则您的新值将被忽略。
您的测试中的另一个考虑因素是，如果您正在启动一个冷站点，第一个请求将招致各种与 jitting 等相关的时间惩罚。如果您以突发请求开始冷，他们都将排队，直到站点准备就绪。因此，特别是如果您没有预热您的网站并且测试持续时间很短，您的结果将会出现偏差。
我在运行负载测试之前手动预热应用程序。
在运行负载测试时，我看到几乎 100% 的 CPU 利用率 - 所以不确定增加工作线程/IO 线程是否会有所帮助。此外，问题仍然在于丢失的 65% 的时间去哪儿了。如果我们假设托管请求的所有处理都发生在 begin-requst 和 end-request 之间，那么我们可以合理地假设在 IIS 中花费的时间应该非常少，因此这些值应该更接近。 65% 是大量丢失的时间。

【解决方案2】：

有一种更好的方法可以使用“失败的请求跟踪规则”来查看应用的内部结构

http://learn.iis.net/page.aspx/266/troubleshooting-failed-requests-using-tracing-in-iis-7/

这样您就可以准确地跟踪您的应用在 IIS 中所做的事情

【讨论】：

【解决方案3】：

我建议研究 MvcMiniProfiler。这是一个 NuGet 包，您可以添加和连接（几乎毫不费力），它真正分解了 MVC 应用程序中各个点的执行时间。您可以看到每个请求的实时视图以及任何瓶颈所在的位置。

更多信息：

【讨论】：

【解决方案4】：

它很可能是 Managed Pipeline 开销和您的 network（甚至是 localhost 或 127.0.0.0）的组合。 0.1) 可能是可以解释“损失”时间的地方。

您提到 IIS 记录与您的 Visual Studio 负载相符测试数据 - 两者都涉及网络堆栈和托管管道。
您的秒表代码仅在 ASP.NET 上下文中执行（仅在 ASP.NET 执行开始之前和结束之前），并且不考虑处理 TCP 网络请求、解析的 IIS 开销请求和响应以及传输时间的 HTTP 标头通过托管管道和 TCP 堆栈。
[EDIT] 如果您的 ASP.NET 页面执行时间真的很快，例如相对于 TCP 堆栈的其余部分和为您编组 HTTP 请求的托管管道，它不会消耗大量 CPU

【讨论】：

【解决方案5】：

如果您遇到加载时间过长的问题，如果您有大量的 IO 操作，这可能与几件事有关如果您正在使用 orm 进行数据库查询，请尝试使用 sql profiler 或在 profiler 内置的 sql 服务器中分析您的 sql 语句如果您收到很多单独的查询，您可能需要考虑在 linq 查询中使用一些包含来捆绑将您的一些数据合并到单个查询中

如果您有大量 IO 操作，您可能还需要考虑使用异步控制器来缩短响应时间，这样您的应用程序就不会持续等待每个 io 操作完成见wintellect.com/CS/blogs/jprosise/archive/2010/03/29/…

还有比 iis 日志记录更好的日志记录解决方案，因为它是一个相当古老的组件，您可能需要查看 log4net 以获得更通用的日志记录或 elmah 来记录错误和异常，因为这些解决方案可以捆绑一堆日志条目和在单个操作中写入多个条目也提高了 IO 性能

【讨论】：

在秒表计时中应考虑代码中的等待 IO - 因此 IIS 中报告的内容与秒表报告的内容之间不应存在差距。