前言
.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 Configure(Action 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 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 _beginRequestPipelineScope = LoggerMessage.DefineScope( "HTTP {HttpMethod} {Uri} {CorrelationId}"); private static readonly Action _requestPipelineStart = LoggerMessage.Define( LogLevel.Information, EventIds.PipelineStart, "Start processing HTTP request {HttpMethod} {Uri} [Correlation: {CorrelationId}]"); private static readonly Action _requestPipelineEnd = LoggerMessage.Define( 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());
发起两次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日志无法追踪的思路和方案，只是引子，重写Handler过程是关键。思考+实践+UML制图，希望能给大家一些启发。
