【譯】.NET 8 網(wǎng)絡(luò)改進(jìn)（二）

原文 | Máňa，Natalia Kondratyeva

翻譯 | 鄭子銘

修改 HttpClient 日志記錄

自定義（甚至簡(jiǎn)單地關(guān)閉）HttpClientFactory 日志記錄是長期請(qǐng)求的功能之一 (dotnet/runtime#77312)。

舊日志記錄概述

HttpClientFactory 添加的默認(rèn)（“舊”）日志記錄非常詳細(xì)，每個(gè)請(qǐng)求發(fā)出 8 條日志消息：

使用請(qǐng)求 URI 啟動(dòng)通知 — 在通過委托處理程序管道傳播之前；
請(qǐng)求標(biāo)頭 - 在處理程序管道之前；
使用請(qǐng)求 URI 啟動(dòng)通知 — 在處理程序管道之后；
請(qǐng)求標(biāo)頭——處理程序管道之后；
在通過委托處理程序管道將響應(yīng)傳播回之前，停止通知已用時(shí)間；
響應(yīng)頭——在傳播回響應(yīng)之前；
停止通知并顯示經(jīng)過的時(shí)間——在傳播回響應(yīng)之后；
響應(yīng)標(biāo)頭 - 將響應(yīng)傳播回來之后。

這可以用下圖來說明。在此圖和下圖中，* 和 [...] 表示日志記錄事件（在默認(rèn)實(shí)現(xiàn)中，日志消息被寫入 ILogger），--> 表示通過應(yīng)用程序?qū)雍蛡鬏攲拥臄?shù)據(jù)流。

  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 <--

默認(rèn) HttpClientFactory 日志記錄的控制臺(tái)輸出如下所示：

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:
      ....

請(qǐng)注意，為了查看跟蹤級(jí)別消息，您需要在全局日志記錄配置文件中或通過 SetMinimumLevel(LogLevel.Trace) 選擇加入該消息。但即使只考慮信息性消息，“舊”日志記錄每個(gè)請(qǐng)求仍然有 4 條消息。

要?jiǎng)h除默認(rèn)（或之前添加的）日志記錄，您可以使用新的RemoveAllLoggers() 擴(kuò)展方法。它與上面“為所有客戶端設(shè)置默認(rèn)值”部分中描述的ConfigureHttpClientDefaults API 結(jié)合起來特別強(qiáng)大。這樣，您可以在一行中刪除所有客戶端的“舊”日志記錄：

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

如果您需要恢復(fù)“舊”日志記錄，例如對(duì)于特定客戶端，您可以使用 AddDefaultLogger() 來執(zhí)行此操作。

添加自定義日志記錄

除了能夠刪除“舊”日志記錄之外，新的 HttpClientFactory API 還允許您完全自定義日志記錄。您可以指定當(dāng) HttpClient 啟動(dòng)請(qǐng)求、接收響應(yīng)或引發(fā)異常時(shí)記錄的內(nèi)容和方式。

如果您選擇這樣做，您可以同時(shí)添加多個(gè)自定義記錄器 - 例如，控制臺(tái)和 ETW 記錄器，或“包裝”和“不包裝”記錄器。由于其附加性質(zhì)，您可能需要事先顯式刪除默認(rèn)的“舊”日志記錄。

要添加自定義日志記錄，您需要實(shí)現(xiàn) IHttpClientLogger 接口，然后使用 AddLogger 將自定義記錄器添加到客戶端。請(qǐng)注意，日志記錄實(shí)現(xiàn)不應(yīng)引發(fā)任何異常，否則可能會(huì)中斷請(qǐng)求執(zhí)行。

登記：

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

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

示例記錄器實(shí)現(xiàn)：

// 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)

請(qǐng)求上下文對(duì)象

上下文對(duì)象可用于將 LogRequestStart 調(diào)用與相應(yīng)的 LogRequestStop 調(diào)用相匹配，以將數(shù)據(jù)從一個(gè)調(diào)用傳遞到另一個(gè)調(diào)用。 Context 對(duì)象由 LogRequestStart 生成，然后傳遞回 LogRequestStop。這可以是屬性包或保存必要數(shù)據(jù)的任何其他對(duì)象。

如果不需要上下文對(duì)象，實(shí)現(xiàn)可以從 LogRequestStart 返回 null。

以下示例顯示了如何使用上下文對(duì)象來傳遞自定義請(qǐng)求標(biāo)識(shí)符。

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

避免從內(nèi)容流中讀取

例如，如果您打算閱讀和記錄請(qǐng)求和響應(yīng)內(nèi)容，請(qǐng)注意，它可能會(huì)對(duì)最終用戶體驗(yàn)產(chǎn)生不利的副作用并導(dǎo)致錯(cuò)誤。例如，請(qǐng)求內(nèi)容可能在發(fā)送之前被消耗，或者巨大的響應(yīng)內(nèi)容可能最終被緩沖在內(nèi)存中。此外，在 .NET 7 之前，訪問標(biāo)頭不是線程安全的，可能會(huì)導(dǎo)致錯(cuò)誤和意外行為。

謹(jǐn)慎使用異步日志記錄

我們期望同步 IHttpClientLogger 接口適用于絕大多數(shù)自定義日志記錄用例。出于性能原因，建議不要在日志記錄中使用異步。但是，如果嚴(yán)格要求日志記錄中的異步訪問，您可以實(shí)現(xiàn)異步版本 IHttpClientAsyncLogger。它派生自 IHttpClientLogger，因此可以使用相同的 AddLogger API 進(jìn)行注冊(cè)。

請(qǐng)注意，在這種情況下，還應(yīng)該實(shí)現(xiàn)日志記錄方法的同步對(duì)應(yīng)項(xiàng)，特別是如果該實(shí)現(xiàn)是面向 .NET Standard 或 .NET 5+ 的庫的一部分。同步對(duì)應(yīng)項(xiàng)是從同步 HttpClient.Send 方法調(diào)用的；即使 .NET Standard 表面不包含它們，.NET Standard 庫也可以在 .NET 5+ 應(yīng)用程序中使用，因此最終用戶可以訪問同步 HttpClient.Send 方法。

包裝和不包裝記錄儀

當(dāng)您添加記錄器時(shí)，您可以顯式設(shè)置wrapHandlersPipeline參數(shù)來指定記錄器是否將被

包裝處理程序管道（添加到管道的頂部，對(duì)應(yīng)于上面舊日志記錄概述部分中的 1、2、7 和 8 號(hào)消息）

  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 <--

或者，不包裝處理程序管道（添加到底部，對(duì)應(yīng)于上面舊日志記錄概述部分中的第 3、4、5 和 6 號(hào)消息）。

  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 <--

默認(rèn)情況下，記錄器添加為不包裝。

在將重試處理程序添加到管道的情況下（例如 Polly 或某些重試的自定義實(shí)現(xiàn)），包裝和不包裝管道之間的區(qū)別最為顯著。在這種情況下，包裝記錄器（位于頂部）將記錄有關(guān)單個(gè)成功請(qǐng)求的消息，記錄的經(jīng)過時(shí)間將是從用戶發(fā)起請(qǐng)求到收到響應(yīng)的總時(shí)間。非包裝記錄器（位于底部）將記錄每次重試迭代，第一個(gè)可能記錄異常或不成功的狀態(tài)代碼，最后一個(gè)記錄成功。每種情況下消耗的時(shí)間都是純粹在主處理程序中花費(fèi)的時(shí)間（實(shí)際在網(wǎng)絡(luò)上發(fā)送請(qǐng)求的處理程序，例如 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

本作品采用知識(shí)共享署名-非商業(yè)性使用-相同方式共享 4.0 國際許可協(xié)議進(jìn)行許可。

歡迎轉(zhuǎn)載、使用、重新發(fā)布，但務(wù)必保留文章署名鄭子銘（包含鏈接： http://www.rzrgm.cn/MingsonZheng/ ），不得用于商業(yè)目的，基于本文修改后的作品務(wù)必以相同的許可發(fā)布。

如有任何疑問，請(qǐng)與我聯(lián)系 (MingsonZheng@outlook.com)

posted @ 2024-02-11 13:46 鄭子銘閱讀(650) 評(píng)論(1) 收藏舉報(bào)

刷新頁面返回頂部

MingsonZheng