诊断磁盘 I/O 瓶颈？答案

【问题标题】：Diagnosing a disk I/O bottleneck?诊断磁盘 I/O 瓶颈？
【发布时间】：2013-07-15 22:52:15
【问题描述】：

我在 Windows 2008 服务器 R2 上安装了一个 .NET 服务，该服务器在具有 6 个 Xeon 内核的 VDI 中运行。在此问题发生期间，此服务的 CPU 利用率平均约为 10-20%，尽管间歇性地发生 DB 超时。

我的应用确实是盒子上唯一的东西，CPU 使用率让我相信以下不是 CPU 瓶颈或时间/切片问题。

我们使用 log4net 进行日志记录

<appender name="LogFileAppender" type="log4net.Appender.RollingFileAppender">
      <File value="C:\app\service.log" />
      <AppendToFile value="true" />
      <rollingStyle value="Date" />
      <datePattern value="yyyyMMdd" />
      <layout type="log4net.Layout.PatternLayout">
        <param name="ConversionPattern" value="%date{yyyy-MM-dd hh:mm:ss:fff} %-5level %logger - %message%newline" />
      </layout>
    </appender>

我有以下代码，删除了实际长时间运行的部分

DateTime mst = DateTime.Now;

//...really long running code

DateTime st = DateTime.Now;

//...more long running code

DateTime et = DateTime.Now;
LogHelper.LogMessage("REGISTRATION: " + subscriber.Principal.Identity.Name + " packaging complete in " + (et - st).TotalMilliseconds + "ms");

et = DateTime.Now;
LogHelper.LogMessage("REGISTRATION: " + subscriber.Principal.Identity.Name + " Registration complete in " + (et - mst).TotalMilliseconds + "ms");

通常我会得到以下日志条目

2013-07-15 07:00:02:238 DEBUG (T:118)Register - REGISTRATION: CORP\user packaging complete in 15.6001ms
2013-07-15 07:00:02:238 DEBUG (T:118)Register - REGISTRATION: CORP\user Registration complete in 1294.8083ms

但今天我得到了以下内容

2013-07-15 11:35:02:498 DEBUG (T:70)Register - REGISTRATION: CORP\user packaging complete in 12589.2807ms
2013-07-15 11:35:04:386 DEBUG (T:70)Register - REGISTRATION: CORP\user Registration complete in 56768.7639ms

在查看时间戳时，两个日志条目的写入间隔为 1888 毫秒，比正常执行的整个持续时间长。

如何衡量这是否实际上是由磁盘 I/O 瓶颈引起的？
还有什么可以解释日志条目之间的 1888 毫秒通常我得到 0 的原因？

我正在考虑使用implementing this solution 来帮助消除 I/O 作为可能的原因。

【问题讨论】：

初步迹象看起来可能是高内存消耗导致我们交换到磁盘。 PerfMon 正在显示页面错误增量。

标签： .net multithreading performance log4net-appender

【解决方案1】：

我们最终使用 Red-Gate 的 ANTS 配置文件来识别服务“软重启”期间的内存泄漏（处置/重新分配对象）。正常的操作流程没有问题，内存配置文件平坦，健康状况良好。

只有在我们引入了一个计时器来模拟一系列可能导致软重启的意外问题之后，我们才能够识别越来越多的延迟对象并重现导致大量内存使用和可怕数量的页面错误恶化的问题表现。

我的理论是，所有这些磁盘分页都会影响我们写入日志文件的能力以及分配新对象的能力。

【讨论】：