1

【译】.NET 8 网络改进(二) - 郑子铭

 7 months ago
source link: https://www.cnblogs.com/MingsonZheng/p/18013332
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.
neoserver,ios ssh client

原文 | Máňa,Natalia Kondratyeva

翻译 | 郑子铭

修改 HttpClient 日志记录

自定义(甚至简单地关闭)HttpClientFactory 日志记录是长期请求的功能之一 (dotnet/runtime#77312)。

旧日志记录概述

HttpClientFactory 添加的默认(“旧”)日志记录非常详细,每个请求发出 8 条日志消息:

  1. 使用请求 URI 启动通知 — 在通过委托处理程序管道传播之前;
  2. 请求标头 - 在处理程序管道之前;
  3. 使用请求 URI 启动通知 — 在处理程序管道之后;
  4. 请求标头——处理程序管道之后;
  5. 在通过委托处理程序管道将响应传播回之前,停止通知已用时间;
  6. 响应头——在传播回响应之前;
  7. 停止通知并显示经过的时间——在传播回响应之后;
  8. 响应标头 - 将响应传播回来之后。

这可以用下图来说明。在此图和下图中,* 和 [...] 表示日志记录事件(在默认实现中,日志消息被写入 ILogger),--> 表示通过应用程序层和传输层的数据流。

  Request -->
*   [Start notification]    // "Start processing HTTP request ..." (1)
*   [Request headers]       // "Request Headers: ..." (2)
      --> Additional Handler #1 -->
        --> .... -->
          --> Additional Handler #N -->
*           [Start notification]    // "Sending HTTP request ..." (3)
*           [Request headers]       // "Request Headers: ..." (4)
                --> Primary Handler -->
                      --------Transport--layer------->
                                          // Server sends response
                      <-------Transport--layer--------
                <-- Primary Handler <--
*           [Stop notification]    // "Received HTTP response ..." (5)
*           [Response headers]     // "Response Headers: ..." (6)
          <-- Additional Handler #N <--
        <-- .... <--
      <-- Additional Handler #1 <--
*   [Stop notification]    // "End processing HTTP request ..." (7)
*   [Response headers]     // "Response Headers: ..." (8)
  Response <--

默认 HttpClientFactory 日志记录的控制台输出如下所示:

var client = _httpClientFactory.CreateClient();
await client.GetAsync("https://httpbin.org/get");
info: System.Net.Http.HttpClient.test.LogicalHandler[100]
      Start processing HTTP request GET https://httpbin.org/get
trce: System.Net.Http.HttpClient.test.LogicalHandler[102]
      Request Headers:
      ....
info: System.Net.Http.HttpClient.test.ClientHandler[100]
      Sending HTTP request GET https://httpbin.org/get
trce: System.Net.Http.HttpClient.test.ClientHandler[102]
      Request Headers:
      ....
info: System.Net.Http.HttpClient.test.ClientHandler[101]
      Received HTTP response headers after 581.2898ms - 200
trce: System.Net.Http.HttpClient.test.ClientHandler[103]
      Response Headers:
      ....
info: System.Net.Http.HttpClient.test.LogicalHandler[101]
      End processing HTTP request after 618.9736ms - 200
trce: System.Net.Http.HttpClient.test.LogicalHandler[103]
      Response Headers:
      ....

请注意,为了查看跟踪级别消息,您需要在全局日志记录配置文件中或通过 SetMinimumLevel(LogLevel.Trace) 选择加入该消息。但即使只考虑信息性消息,“旧”日志记录每个请求仍然有 4 条消息。

要删除默认(或之前添加的)日志记录,您可以使用新的RemoveAllLoggers() 扩展方法。它与上面“为所有客户端设置默认值”部分中描述的ConfigureHttpClientDefaults API 结合起来特别强大。这样,您可以在一行中删除所有客户端的“旧”日志记录:

services.ConfigureHttpClientDefaults(b => b.RemoveAllLoggers()); // remove HttpClientFactory default logging for all clients

如果您需要恢复“旧”日志记录,例如对于特定客户端,您可以使用 AddDefaultLogger() 来执行此操作。

添加自定义日志记录

除了能够删除“旧”日志记录之外,新的 HttpClientFactory API 还允许您完全自定义日志记录。您可以指定当 HttpClient 启动请求、接收响应或引发异常时记录的内容和方式。

如果您选择这样做,您可以同时添加多个自定义记录器 - 例如,控制台和 ETW 记录器,或“包装”和“不包装”记录器。由于其附加性质,您可能需要事先显式删除默认的“旧”日志记录。

要添加自定义日志记录,您需要实现 IHttpClientLogger 接口,然后使用 AddLogger 将自定义记录器添加到客户端。请注意,日志记录实现不应引发任何异常,否则可能会中断请求执行。

services.AddSingleton<SimpleConsoleLogger>(); // register the logger in DI

services.AddHttpClient("foo") // add a client
    .RemoveAllLoggers() // remove previous logging
    .AddLogger<SimpleConsoleLogger>(); // add the custom logger

示例记录器实现:

// outputs one line per request to console
public class SimpleConsoleLogger : IHttpClientLogger
{
    public object? LogRequestStart(HttpRequestMessage request) => null;

    public void LogRequestStop(object? ctx, HttpRequestMessage request, HttpResponseMessage response, TimeSpan elapsed)
        => Console.WriteLine($"{request.Method} {request.RequestUri?.AbsoluteUri} - {(int)response.StatusCode} {response.StatusCode} in {elapsed.TotalMilliseconds}ms");

    public void LogRequestFailed(object? ctx, HttpRequestMessage request, HttpResponseMessage? response, Exception e, TimeSpan elapsed)
        => Console.WriteLine($"{request.Method} {request.RequestUri?.AbsoluteUri} - Exception {e.GetType().FullName}: {e.Message}");
}

示例输出:

var client = _httpClientFactory.CreateClient("foo");
await client.GetAsync("https://httpbin.org/get");
await client.PostAsync("https://httpbin.org/post", new ByteArrayContent(new byte[] { 42 }));
await client.GetAsync("http://httpbin.org/status/500");
await client.GetAsync("http://localhost:1234");
GET https://httpbin.org/get - 200 OK in 393.2039ms
POST https://httpbin.org/post - 200 OK in 95.524ms
GET https://httpbin.org/status/500 - 500 InternalServerError in 99.5025ms
GET http://localhost:1234/ - Exception System.Net.Http.HttpRequestException: No connection could be made because the target machine actively refused it. (localhost:1234)

请求上下文对象

上下文对象可用于将 LogRequestStart 调用与相应的 LogRequestStop 调用相匹配,以将数据从一个调用传递到另一个调用。 Context 对象由 LogRequestStart 生成,然后传递回 LogRequestStop。这可以是属性包或保存必要数据的任何其他对象。

如果不需要上下文对象,实现可以从 LogRequestStart 返回 null。

以下示例显示了如何使用上下文对象来传递自定义请求标识符。

public class RequestIdLogger : IHttpClientLogger
{
    private readonly ILogger _log;

    public RequestIdLogger(ILogger<RequestIdLogger> log)
    {
        _log = log;
    }

    private static readonly Action<ILogger, Guid, string?, Exception?> _requestStart =
        LoggerMessage.Define<Guid, string?>(
            LogLevel.Information,
            EventIds.RequestStart,
            "Request Id={RequestId} ({Host}) started");

    private static readonly Action<ILogger, Guid, double, Exception?> _requestStop =
        LoggerMessage.Define<Guid, double>(
            LogLevel.Information,
            EventIds.RequestStop,
            "Request Id={RequestId} succeeded in {elapsed}ms");

    private static readonly Action<ILogger, Guid, Exception?> _requestFailed =
        LoggerMessage.Define<Guid>(
            LogLevel.Error,
            EventIds.RequestFailed,
            "Request Id={RequestId} FAILED");

    public object? LogRequestStart(HttpRequestMessage request)
    {
        var ctx = new Context(Guid.NewGuid());
        _requestStart(_log, ctx.RequestId, request.RequestUri?.Host, null);
        return ctx;
    }

    public void LogRequestStop(object? ctx, HttpRequestMessage request, HttpResponseMessage response, TimeSpan elapsed)
        => _requestStop(_log, ((Context)ctx!).RequestId, elapsed.TotalMilliseconds, null);

    public void LogRequestFailed(object? ctx, HttpRequestMessage request, HttpResponseMessage? response, Exception e, TimeSpan elapsed)
        => _requestFailed(_log, ((Context)ctx!).RequestId, null);

    public static class EventIds
    {
        public static readonly EventId RequestStart = new(1, "RequestStart");
        public static readonly EventId RequestStop = new(2, "RequestStop");
        public static readonly EventId RequestFailed = new(3, "RequestFailed");
    }

    record Context(Guid RequestId);
}
info: RequestIdLogger[1]
      Request Id=d0d63b84-cd67-4d21-ae9a-b63d26dfde50 (httpbin.org) started
info: RequestIdLogger[2]
      Request Id=d0d63b84-cd67-4d21-ae9a-b63d26dfde50 succeeded in 530.1664ms
info: RequestIdLogger[1]
      Request Id=09403213-dd3a-4101-88e8-db8ab19e1eeb (httpbin.org) started
info: RequestIdLogger[2]
      Request Id=09403213-dd3a-4101-88e8-db8ab19e1eeb succeeded in 83.2484ms
info: RequestIdLogger[1]
      Request Id=254e49bd-f640-4c56-b62f-5de678eca129 (httpbin.org) started
info: RequestIdLogger[2]
      Request Id=254e49bd-f640-4c56-b62f-5de678eca129 succeeded in 162.7776ms
info: RequestIdLogger[1]
      Request Id=e25ccb08-b97e-400d-b42b-b09d6c42adec (localhost) started
fail: RequestIdLogger[3]
      Request Id=e25ccb08-b97e-400d-b42b-b09d6c42adec FAILED

避免从内容流中读取

例如,如果您打算阅读和记录请求和响应内容,请注意,它可能会对最终用户体验产生不利的副作用并导致错误。例如,请求内容可能在发送之前被消耗,或者巨大的响应内容可能最终被缓冲在内存中。此外,在 .NET 7 之前,访问标头不是线程安全的,可能会导致错误和意外行为。

谨慎使用异步日志记录

我们期望同步 IHttpClientLogger 接口适用于绝大多数自定义日志记录用例。出于性能原因,建议不要在日志记录中使用异步。但是,如果严格要求日志记录中的异步访问,您可以实现异步版本 IHttpClientAsyncLogger。它派生自 IHttpClientLogger,因此可以使用相同的 AddLogger API 进行注册。

请注意,在这种情况下,还应该实现日志记录方法的同步对应项,特别是如果该实现是面向 .NET Standard 或 .NET 5+ 的库的一部分。同步对应项是从同步 HttpClient.Send 方法调用的;即使 .NET Standard 表面不包含它们,.NET Standard 库也可以在 .NET 5+ 应用程序中使用,因此最终用户可以访问同步 HttpClient.Send 方法。

包装和不包装记录仪

当您添加记录器时,您可以显式设置wrapHandlersPipeline参数来指定记录器是否将被

  • 包装处理程序管道(添加到管道的顶部,对应于上面旧日志记录概述部分中的 1、2、7 和 8 号消息)
  Request -->
*   [LogRequestStart()]                // wrapHandlersPipeline=TRUE
      --> Additional Handlers #1..N -->    // handlers pipeline
          --> Primary Handler -->
                --------Transport--layer--------
          <-- Primary Handler <--
      <-- Additional Handlers #N..1 <--    // handlers pipeline
*   [LogRequestStop()]                 // wrapHandlersPipeline=TRUE
  Response <--
  • 或者,不包装处理程序管道(添加到底部,对应于上面旧日志记录概述部分中的第 3、4、5 和 6 号消息)。
  Request -->
    --> Additional Handlers #1..N --> // handlers pipeline
*     [LogRequestStart()]             // wrapHandlersPipeline=FALSE
          --> Primary Handler -->
                --------Transport--layer--------
          <-- Primary Handler <--
*     [LogRequestStop()]              // wrapHandlersPipeline=FALSE
    <-- Additional Handlers #N..1 <-- // handlers pipeline
  Response <--

默认情况下,记录器添加为不包装。

在将重试处理程序添加到管道的情况下(例如 Polly 或某些重试的自定义实现),包装和不包装管道之间的区别最为显着。在这种情况下,包装记录器(位于顶部)将记录有关单个成功请求的消息,记录的经过时间将是从用户发起请求到收到响应的总时间。非包装记录器(位于底部)将记录每次重试迭代,第一个可能记录异常或不成功的状态代码,最后一个记录成功。每种情况下消耗的时间都是纯粹在主处理程序中花费的时间(实际在网络上发送请求的处理程序,例如 HttpClientHandler)。

这可以用下图来说明:

  • 包装案例 (wrapHandlersPipeline=TRUE)
  Request -->
*   [LogRequestStart()]
        --> Additional Handlers #1..(N-1) -->
            --> Retry Handler -->
              --> //1
                  --> Primary Handler -->
                  <-- "503 Service Unavailable" <--
              --> //2
                  --> Primary Handler ->
                  <-- "503 Service Unavailable" <--
              --> //3
                  --> Primary Handler -->
                  <-- "200 OK" <--
            <-- Retry Handler <--
        <-- Additional Handlers #(N-1)..1 <--
*   [LogRequestStop()]
  Response <--
info: Example.CustomLogger.Wrapping[1]
      GET https://consoto.com/
info: Example.CustomLogger.Wrapping[2]
      200 OK - 809.2135ms
  • 不包装案例 (wrapHandlersPipeline=FALSE)
  Request -->
    --> Additional Handlers #1..(N-1) -->
        --> Retry Handler -->
          --> //1
*           [LogRequestStart()]
                --> Primary Handler -->
                <-- "503 Service Unavailable" <--
*           [LogRequestStop()]
          --> //2
*           [LogRequestStart()]
                --> Primary Handler -->
                <-- "503 Service Unavailable" <--
*           [LogRequestStop()]
          --> //3
*           [LogRequestStart()]
                --> Primary Handler -->
                <-- "200 OK" <--
*           [LogRequestStop()]
        <-- Retry Handler <--
    <-- Additional Handlers #(N-1)..1 <--
  Response <--
info: Example.CustomLogger.NotWrapping[1]
      GET https://consoto.com/
info: Example.CustomLogger.NotWrapping[2]
      503 Service Unavailable - 98.613ms
info: Example.CustomLogger.NotWrapping[1]
      GET https://consoto.com/
info: Example.CustomLogger.NotWrapping[2]
      503 Service Unavailable - 96.1932ms
info: Example.CustomLogger.NotWrapping[1]
      GET https://consoto.com/
info: Example.CustomLogger.NotWrapping[2]
      200 OK - 579.2133ms

.NET 8 Networking Improvements

本作品采用知识共享署名-非商业性使用-相同方式共享 4.0 国际许可协议进行许可。

欢迎转载、使用、重新发布,但务必保留文章署名 郑子铭 (包含链接: http://www.cnblogs.com/MingsonZheng/ ),不得用于商业目的,基于本文修改后的作品务必以相同的许可发布。

如有任何疑问,请与我联系 ([email protected])


About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK