HttpClientFactory日志不好用,自己扩展一个?
前言
.NetCore2.1新推出HttpClientFactory工廠類, 替代了早期的HttpClient,并新增了彈性Http調用機制 (集成Policy組件)。
替換的初衷還是簡單說下:
①? using(var client= new HttpClient()) 調用Dispose()方法,并不會很快釋放底層Socket連接,同時新建Socket需要時間,這在高并發場景下Socket耗盡。?傳送門
②? 由于①很多人會想到用單例或靜態類構建HttpClient實例,但是這里還有一個坑,HttpClient會忽略DNS的變化。?傳送門
HttpClientFactory 以一種模塊化、可命名、彈性可預期的方式重建了HttpClient的使用方式。HttpClientFactory以依賴注入的方式集成到.NETCore 框架:
?HttpClientFactory典型用法
使用時從IHttpClientFactory工廠創建所需HttpClient實例,發起業務端請求。
觀察Info級別日志:
19/12/04?11:06:46?[Info].[System.Net.Http.HttpClient.bce-request.LogicalHandler].[18}].[]Start?processing?HTTP?request?GET?http://localhost:5000/v1/eqid/b827a9400004132a000000065dc26470?19/12/04?11:06:46?[Info].[System.Net.Http.HttpClient.bce-request.ClientHandler].[18}].[]
Sending?HTTP?request?GET?http://localhost:5000/v1/eqid/b827a9400004132a000000065dc26470?19/12/04?11:06:46?[Info].[System.Net.Http.HttpClient.bce-request.ClientHandler].[34}].[]
Received?HTTP?response?after?174.5088ms?-?OK?
19/12/04?11:06:46?[Info].[System.Net.Http.HttpClient.bce-request.LogicalHandler].[34}].[]
End?processing?HTTP?request?after?211.1478ms?-?OK
一切都是那么自然、優雅。
頭腦風暴
觀察上面單次請求的日志,由外層LogicHandler和內層ClientHandler?日志頭組成。這樣的日志可以想象到有2個問題:
① 在高并發使用HttpClient,日志條數眾多,沒有類似TraceId 這樣的機制定位 某次HttpClient調用的完整日志。?
?②? 若是微服務/ 分布式調用,可能還有 將本次HttpClient調用日志與后置api日志 結合分析的需求, 這個日志也支持不了。
因此本文打算重新構建 HttpClientFactory日志:給某次請求的全部日志設置TraceId
結合我給出的典型用法來看IHttpClientFactory組件原理:
示例中System.Net.Http.HttpClient.bce-request.LogicalHandler,System.Net.Http.HttpClient.bce-request.ClientHandler?日志頭即是來自LoggingScopeHttpMessageHandler?,LoggingHttpMessageHandler 兩個處理器。
給出手繪的UML類圖:?
?
本次要擴展的入口便是IHttpMessageHandlerFilter接口,核心是自定義DelegatingHandler日志處理器。
編程實踐
? ?如以上分析,使用aspNetCore2.2需要做如下擴展:
P1
實現IHttpMessageHandlerFilter接口,移除接口中默認的2個日志處理器
public class TraceIdLoggingMessageHandlerFilter : IHttpMessageHandlerBuilderFilter{
private readonly ILoggerFactory _loggerFactory;
public TraceIdLoggingMessageHandlerFilter(ILoggerFactory loggerFactory)
{
_loggerFactory = loggerFactory ?? throw new ArgumentNullException(nameof(loggerFactory));
}
public Action<HttpMessageHandlerBuilder> Configure(Action<HttpMessageHandlerBuilder> next)
{
if (next == null)
{
throw new ArgumentNullException(nameof(next));
}
return (builder) =>
{
// Run other configuration first, we want to decorate.
next(builder);
var outerLogger =_loggerFactory.CreateLogger($"System.Net.Http.HttpClient.{builder.Name}.LogicalHandler");
builder.AdditionalHandlers.Clear();
builder.AdditionalHandlers.Insert(0,new CustomLoggingScopeHttpMessageHandler(outerLogger));
};
}
}
P2
?實現帶有TraceId能力的HttpClient?日志處理器,并加入到IHttpMessageHandlerFilter接口實現類
public class CustomLoggingScopeHttpMessageHandler : DelegatingHandler{
private readonly ILogger _logger;
public CustomLoggingScopeHttpMessageHandler(ILogger logger)
{
_logger = logger ?? throw new ArgumentNullException(nameof(logger));
}
protected override async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request,
CancellationToken cancellationToken)
{
if (request == null)
{
throw new ArgumentNullException(nameof(request));
}
using (Log.BeginRequestPipelineScope(_logger, request))
{
Log.RequestPipelineStart(_logger, request);
var response = await base.SendAsync(request, cancellationToken);
Log.RequestPipelineEnd(_logger, response);
return response;
}
}
private static class Log
{
private static class EventIds
{
public static readonly EventId PipelineStart = new EventId(100, "RequestPipelineStart");
public static readonly EventId PipelineEnd = new EventId(101, "RequestPipelineEnd");
}
private static readonly Func<ILogger, HttpMethod, Uri, string, IDisposable> _beginRequestPipelineScope =
LoggerMessage.DefineScope<HttpMethod, Uri, string>(
"HTTP {HttpMethod} {Uri} {CorrelationId}");
private static readonly Action<ILogger, HttpMethod, Uri, string, Exception> _requestPipelineStart =
LoggerMessage.Define<HttpMethod, Uri, string>(
LogLevel.Information,
EventIds.PipelineStart,
"Start processing HTTP request {HttpMethod} {Uri} [Correlation: {CorrelationId}]");
private static readonly Action<ILogger, HttpStatusCode,string,Exception> _requestPipelineEnd =
LoggerMessage.Define<HttpStatusCode,string>(
LogLevel.Information,
EventIds.PipelineEnd,
"End processing HTTP request - {StatusCode}, [Correlation: {CorrelationId}]");
public static IDisposable BeginRequestPipelineScope(ILogger logger, HttpRequestMessage request)
{
var correlationId = GetCorrelationIdFromRequest(request);
return _beginRequestPipelineScope(logger, request.Method, request.RequestUri, correlationId);
}
public static void RequestPipelineStart(ILogger logger, HttpRequestMessage request)
{
var correlationId = GetCorrelationIdFromRequest(request);
_requestPipelineStart(logger, request.Method, request.RequestUri, correlationId, null);
}
public static void RequestPipelineEnd(ILogger logger, HttpResponseMessage response)
{
var correlationId = GetCorrelationIdFromRequest(response.RequestMessage);
_requestPipelineEnd(logger, response.StatusCode, correlationId, null);
}
private static string GetCorrelationIdFromRequest(HttpRequestMessage request)
{
string correlationId = Guid.NewGuid().ToString();
if (request.Headers.TryGetValues("X-Correlation-ID", out var values))
correlationId = values.First();
else
request.Headers.Add("X-Correlation-ID",correlationId);
return correlationId;
}
}
}
?? 以上TraceId的實現思路,參考了我前一篇博文《被忽略的TraceId,可以用起來了》的思路,為每次HttpClient調用過程設定? 全局唯一的GUID標記, 后置api服務可酌情修改以上代碼處理。》其中寫入日志的代碼Copy自HttpClientFactory源代碼。
P3
?在DI框架中替換原有的IHttpMessageHandlerFilter實現
services.Replace(ServiceDescriptor.Singleton<IHttpMessageHandlerBuilderFilter, TraceIdLoggingMessageHandlerFilter>());發起兩次HttpClient請求, 輸出的日志如下:
19/12/04 12:59:22 [Info].[System.Net.Http.HttpClient.bce-request.LogicalHandler].[17}].[]Start processing HTTP request GET http://localhost:5000/v1/eqid/ad78deef00444ed7000000035de704e8 [Correlation: 03de676d-680e-4a92-aef5-749bcc3ba499]
19/12/04 12:59:22 [Info].[System.Net.Http.HttpClient.bce-request.LogicalHandler].[4}].[]
End processing HTTP request - OK, [Correlation: 03de676d-680e-4a92-aef5-749bcc3ba499]
19/12/04 12:59:48 [Info].[System.Net.Http.HttpClient.bce-request.LogicalHandler].[17}].[]
Start processing HTTP request GET http://localhost:5000/v1/eqid/8ea0c3b66b60f0ff100000005de704fb [Correlation: 6f14393a-3a2b-45c4-a9b4-0b4ab874ef1d]
19/12/04 12:59:48 [Info].[System.Net.Http.HttpClient.bce-request.LogicalHandler].[42}].[]
End processing HTTP request - OK, [Correlation: 6f14393a-3a2b-45c4-a9b4-0b4ab874ef1d]
可以看到每次請求的開始和結束都帶上了設定的GUID TraceId。
Tip
?① 這個TraceId 可以使用你業務上獨具一格的標記,這樣在排查時, 能根據上游業務更好的追蹤日志。
?② 目前這個TraceId位于LogMessage,實際上可以為nlog自定義LogoutRenderer,將該TraceId放在顯著位置,便于ETL等日志集成框架過濾。
That's All, 這是本次解決HttpClient日志無法追蹤的思路和方案,思考+實踐+UML制圖,希望能給大家一些啟發。
+?https://github.com/aspnet/HttpClientFactory/blob/master/src/Microsoft.Extensions.Http/Logging/LoggingHttpMessageHandlerBuilderFilter.cs
掃一掃左邊二維碼,
更多驚喜干貨等著你。
............
總結
以上是生活随笔為你收集整理的HttpClientFactory日志不好用,自己扩展一个?的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 微软正在开发基于Rust的安全编程语言
- 下一篇: Quartz.net定时任务的使用及获取