我认为这个问题非常有趣，所以我花了一点时间研究一下 WebHost 实际上是如何测量和显示请求时间的。重点是：没有一种好的、简单的或漂亮的方法来获得这些信息，一切都感觉像是 hack。但如果你还感兴趣，请跟着看。
当应用程序启动时，WebHostBuilder 构建 WebHost，后者又创建 HostingApplication。那基本上是负责响应传入请求的根组件。它是在请求进入时调用中间件管道的组件。
同时，它也会创建 HostingApplicationDiagnostics，允许收集有关请求处理的诊断信息。在请求开始时，HostingApplication 将调用 HostingApplicationDiagnostics.BeginRequest，而在请求结束时，它将调用 HostingApplicationDiagnostics.RequestEnd。
毫不奇怪，HostingApplicationDiagnostics 是将测量请求持续时间并记录该消息到你看到的 WebHost 的东西。因此，这是我们必须更仔细地检查以找出如何获取信息的类。
诊断对象用于报告诊断信息的有两个东西：记录器和DiagnosticListener。
诊断监听器
DiagnosticListener是一个有趣的东西：它基本上是一个通用的事件接收器,你可以在上面触发事件。然后其他对象就可以订阅它来监听这些事件。所以这对我们的目的几乎听起来完美！
HostingApplicationDiagnostics使用的DiagnosticListener对象由WebHost传递，并且实际上是从依赖注入中解析出来的。由于它被WebHostBuilder注册为单例,我们实际上只需从依赖注入中解析监听器并订阅其事件即可。因此，让我们在Startup中这样做：
public void ConfigureServices(IServiceCollection services)
{
services.AddSingleton<DiagnosticObserver>();
}
public void Configure(IApplicationBuilder app, IHostingEnvironment env,
// we inject both the DiagnosticListener and our DiagnosticObserver here
DiagnosticListener diagnosticListenerSource, DiagnosticObserver diagnosticObserver)
{
diagnosticListenerSource.Subscribe(diagnosticObserver);
}
这已经足够让我们运行
DiagnosticObserver。我们的观察者需要实现
IObserver<KeyValuePair<string, object>>。当事件发生时，我们将获得一个键值对，其中键是事件的标识符，而值是通过
HostingApplicationDiagnostics传递的自定义对象。
但在实现我们的观察者之前，我们应该看一下
HostingApplicationDiagnostics实际上引发了哪些事件。
很不幸，当请求结束时，在诊断监听器上引发的事件只传递
结束时间戳，因此我们还需要监听在请求
开始时引发的事件以读取开始时间戳。但这会向我们的观察者引入状态，这是我们想要避免的。此外，实际的事件名称常量
带有已弃用前缀，这可能表明我们应该避免使用它们。
首选方法是使用
活动, 这也与诊断观察者密切相关。活动显然是跟踪应用程序中出现的活动的状态。它们在某些时候启动和停止，并且已经记录了它们自己运行多长时间。因此，我们只需使我们的观察者监听活动的停止事件，即可在完成时得到通知：
public class DiagnosticObserver : IObserver<KeyValuePair<string, object>>
{
private readonly ILogger<DiagnosticObserver> _logger;
public DiagnosticObserver(ILogger<DiagnosticObserver> logger)
{
_logger = logger;
}
public void OnCompleted() { }
public void OnError(Exception error) { }
public void OnNext(KeyValuePair<string, object> value)
{
if (value.Key == "Microsoft.AspNetCore.Hosting.HttpRequestIn.Stop")
{
var httpContext = value.Value.GetType().GetProperty("HttpContext")?.GetValue(value.Value) as HttpContext;
var activity = Activity.Current;
_logger.LogWarning("Request ended for {RequestPath} in {Duration} ms",
httpContext.Request.Path, activity.Duration.TotalMilliseconds);
}
}
}
不幸的是，没有不带缺点的解决方案……我发现这个方案对于并行请求非常不准确（例如，在打开一个包含图像或脚本的页面时也会请求它们）。这可能是因为我们使用静态Activity.Current来获取活动。然而，似乎没有办法只获取单个请求的活动，例如从传递的键值对中获取。
所以我回过头来尝试我的原始想法，再次使用那些已被弃用的事件。我理解的方式是，它们只是被弃用，因为推荐使用活动，而不是因为它们将很快被删除（当然，我们在处理实现细节和内部类，所以这些事情随时可能改变）。为避免并发问题，我们需要确保将状态存储在HTTP上下文中（而不是类字段）：
private const string StartTimestampKey = "DiagnosticObserver_StartTimestamp";
public void OnNext(KeyValuePair<string, object> value)
{
if (value.Key == "Microsoft.AspNetCore.Hosting.BeginRequest")
{
var httpContext = (HttpContext)value.Value.GetType().GetProperty("httpContext").GetValue(value.Value);
httpContext.Items[StartTimestampKey] = (long)value.Value.GetType().GetProperty("timestamp").GetValue(value.Value);
}
else if (value.Key == "Microsoft.AspNetCore.Hosting.EndRequest")
{
var httpContext = (HttpContext)value.Value.GetType().GetProperty("httpContext").GetValue(value.Value);
var endTimestamp = (long)value.Value.GetType().GetProperty("timestamp").GetValue(value.Value);
var startTimestamp = (long)httpContext.Items[StartTimestampKey];
var duration = new TimeSpan((long)((endTimestamp - startTimestamp) * TimeSpan.TicksPerSecond / (double)Stopwatch.Frequency));
_logger.LogWarning("Request ended for {RequestPath} in {Duration} ms",
httpContext.Request.Path, duration.TotalMilliseconds);
}
}
运行时，我们实际上可以得到准确的结果，并且我们还可以访问HttpContext，以便识别请求。当然，这里涉及的开销非常明显：使用反射访问属性值，在HttpContext.Items中存储信息，一般而言，整个观察者的东西...这可能不是一个非常高效的方法。
有关诊断源和活动的进一步阅读：
DiagnosticSource用户指南和
Activity用户指南。
记录日志
在上面的某个地方，我提到
HostingApplicationDiagnostics也会将信息报告给日志记录工具。当然：毕竟这是我们在控制台上看到的。如果我们
查看实现，我们可以看到这已经计算出了正确的持续时间。由于这是结构化日志记录，我们可以使用它来获取该信息。
因此，让我们尝试编写一个自定义记录器，检查
确切的状态对象，看看我们能做些什么：
public class RequestDurationLogger : ILogger, ILoggerProvider
{
public ILogger CreateLogger(string categoryName) => this;
public void Dispose() { }
public IDisposable BeginScope<TState>(TState state) => NullDisposable.Instance;
public bool IsEnabled(LogLevel logLevel) => true;
public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
{
if (state.GetType().FullName == "Microsoft.AspNetCore.Hosting.Internal.HostingRequestFinishedLog" &&
state is IReadOnlyList<KeyValuePair<string, object>> values &&
values.FirstOrDefault(kv => kv.Key == "ElapsedMilliseconds").Value is double milliseconds)
{
Console.WriteLine($"Request took {milliseconds} ms");
}
}
private class NullDisposable : IDisposable
{
public static readonly NullDisposable Instance = new NullDisposable();
public void Dispose() { }
}
}
不幸的是（你现在可能已经喜欢上这个词了，对吧？），状态类HostingRequestFinishedLog是内部的，因此我们无法直接使用它。所以我们必须使用反射来识别它。但我们只需要它的名称，然后就可以从只读列表中提取值。
现在我们只需要将该记录器（提供程序）与 Web 主机注册：
WebHost.CreateDefaultBuilder(args)
.ConfigureLogging(logging =>
{
logging.AddProvider(new RequestDurationLogger());
})
.UseStartup<Startup>()
.Build();
这样我们就能够访问与标准日志记录相同的信息了。
然而，存在两个问题：我们没有HttpContext，因此无法获取有关此持续时间实际上属于哪个请求的信息。并且正如您在HostingApplicationDiagnostics中看到的那样，仅当日志级别至少为Information时才会进行此日志记录调用。
我们可以通过使用反射读取私有字段_httpContext来获取HttpContext，但我们对日志级别无能为力。当然，创建记录器以从一个特定的日志记录调用中获取信息是一种超级黑客行为，可能也不是一个好主意。
结论
因此，这一切都很糟糕。没有干净的方法从HostingApplicationDiagnostics中检索此信息。我们还必须记住，诊断工具实际上只在启用时运行。性能关键的应用程序很可能在某个时候禁用它。无论如何，将此信息用于诊断之外的任何内容都是一个坏主意，因为它通常太脆弱了。
那么什么是更好的解决方案呢？一种在诊断上下文之外运行的解决方案吗？一个简单的中间件可以尽早运行；就像您已经使用过的那样。是的，这可能不太准确，因为它会省略一些来自外部请求处理管道的路径，但它仍然是实际应用程序代码的准确测量。毕竟，如果我们想要衡量框架性能，我们无论如何都必须从外部进行测量：作为客户端，发出请求（就像基准测试工作方式一样）。
顺便说一句，这也是Stack Overflow自己的
MiniProfiler的工作原理。您只需尽早
注册中间件，就这样。
