使用 NLog 給 Asp.Net Core 做請求監控
https://www.cnblogs.com/cheesebar/p/9078207.html
為了減少由於單個請求掛掉而拖垮整站的情況發生，給所有請求做統計是一個不錯的解決方法，通過觀察哪些請求的耗時比較長，我們就可以找到對應的接口、代碼、數據表，做有針對性的優化可以提高效率。在 asp.net web api 中我們可以通過注冊一個 DelegatingHandler 來實現該功能。那在 asp.net core 中該如何實現呢？
一：比較 asp.net web api 和 asp.net core 的請求管道
觀察這兩張圖，可以發現他們非常的相似，都是管道式的設計，在 asp.net web api 中，我們可以注冊一系列的 DelegatingHandler 來處理請求上下文 HttpRequestMessage，在 asp.net core 中，我們可以注冊一系列中間件來處理請求上下文，他們兩者從功能和意義上是非常相似的，我這里這里不會詳細介紹各自的管道是如何的（這樣的文章非常多，博客園隨處可見），他們都完成了類似中間件的功能，只是在代碼設計上有一點區別。
我們先看一段代碼，新建一個 asp.net web api 項目，添加幾個 DelegatinHandler
復制代碼
public class DelegatingHandler1 : DelegatingHandler
{
protected override async Task
{
Trace.WriteLine("DelegatingHandler1 HashCode: " + this.GetHashCode());
Trace.WriteLine("DelegatingHandler1 base InnerHandler HashCode: " + base.InnerHandler.GetHashCode());
Trace.WriteLine("DelegatingHandler1 start");
var response = await base.SendAsync(request, cancellationToken);
Trace.WriteLine("DelegatingHandler1 end");
return response;
}
}
public class DelegatingHandler2 : DelegatingHandler
{
protected override async Task
{
Trace.WriteLine("DelegatingHandler2 HashCode: " + this.GetHashCode());
Trace.WriteLine("DelegatingHandler2 base InnerHandler HashCode: " + base.InnerHandler.GetHashCode());
Trace.WriteLine("DelegatingHandler2 start");
var response = await base.SendAsync(request, cancellationToken);
Trace.WriteLine("DelegatingHandler2 end");
return response;
}
}
public class DelegatingHandler3 : DelegatingHandler
{
protected override async Task
{
Trace.WriteLine("DelegatingHandler3 HashCode: " + this.GetHashCode());
Trace.WriteLine("DelegatingHandler3 base InnerHandler HashCode: " + base.InnerHandler.GetHashCode());
Trace.WriteLine("DelegatingHandler3 start");
var response = await base.SendAsync(request, cancellationToken);
Trace.WriteLine("DelegatingHandler3 end");
return response;
}
}
復制代碼
然后在 Global 中注冊
復制代碼
public class WebApiApplication : System.Web.HttpApplication
{
protected void Application_Start()
{
AreaRegistration.RegisterAllAreas();
GlobalConfiguration.Configure(WebApiConfig.Register);
FilterConfig.RegisterGlobalFilters(GlobalFilters.Filters);
RouteConfig.RegisterRoutes(RouteTable.Routes);
BundleConfig.RegisterBundles(BundleTable.Bundles);
GlobalConfiguration.Configuration.MessageHandlers.Add(new DelegatingHandler1());
GlobalConfiguration.Configuration.MessageHandlers.Add(new DelegatingHandler2());
GlobalConfiguration.Configuration.MessageHandlers.Add(new DelegatingHandler3());
}
}
復制代碼
修改一下 ValuesController
復制代碼
public class ValuesController : ApiController
{
// GET api/values
public IEnumerable
{
Trace.WriteLine("/api/values");
var handlers = this.RequestContext.Configuration.MessageHandlers;
return new string[] { "value1", "value2" };
}
}
復制代碼
啟動后輸入路徑 /api/values，我們可以在VS 的輸出欄看到下面這些內容
DelegatingHandler1 HashCode: 58154627
DelegatingHandler1 base InnerHandler HashCode: 35529478
DelegatingHandler1 start
DelegatingHandler2 HashCode: 35529478
DelegatingHandler2 base InnerHandler HashCode: 47422476
DelegatingHandler2 start
DelegatingHandler3 HashCode: 47422476
DelegatingHandler3 base InnerHandler HashCode: 65273341
DelegatingHandler3 start
/api/values
DelegatingHandler3 end
DelegatingHandler2 end
DelegatingHandler1 end
輸出中我們可以看到 DelegatingHandler1 的 InnerHandler 是 DelegatingHandler2，以此類推，在 DelegatingHandler3 的 InnerHandler 處理請求的時候就轉發到了相關控制器，這里和 .net core 中的中間件非常相似，在.net core 中間件順序是 RequestServicesContainerMiddleware（給請求上下文綁定容器）-> AuthenticationMiddleware（認證）-> RouterMiddleware （路由以及MVC）
如果我們在 ValuesController 中觀察表達式 this.RequestContext.Configuration.MessageHandlers 還可以看到最終處理請求的是一個 HttpRoutingDispatcher，最也是是分配到路由以及控制器來處理的，按照如此方式我們可以很容易在 asp.net web api 中對請求統計。這里是比較簡陋的，對此我們可以記錄客戶端和服務器更詳細的信息，包括 IP 地址，http狀態碼，是否是認證用戶等等，但是這篇主要是以 asp.net core 為主的，所以這里就不詳細寫下去了。
復制代碼
public class ApplicationInsight : DelegatingHandler
{
protected override async Task
{
var stopWatch = new Stopwatch();
stopWatch.Start();
var response = await base.SendAsync(request, cancellationToken);
stopWatch.Stop();
//停止計時器，並記錄
}
}
public partial class Startup
{
public void Configuration(IAppBuilder app)
{
GlobalConfiguration.Configuration.MessageHandlers.Add(new ApplicationInsight());
}
}
復制代碼
二：asp.net core 中間件 + NLog 實現請求監控
先看統計結果，start 開始時間，time 是請求消耗時間（毫秒），authenicate 是認證通過的 schema，使用 NLog 自定義字段也是非常方便的
先說一說遇到的問題
（1）NLog 記錄一張以上的表如何實現，應為首先會有一個一般性的日志表（稱他為 log），並且這些統計不對寫到 log 表
（2）使用 NLog 自定義字段 LayoutRenderer 沒有類似 .net framework 中的 System.Web.Current
（3）使用 UseMiddleware 無法在讓我們的中間件成為第一個中間件
（4）實現忽略記錄的方法，肯定有一些接口是不希望記錄的，所以這個也要實現
NLog 配置
這里只列出了部分內容，github 地址在最后，數據庫是 mysql ，apiinsight 表示請求統計，log 是一般性的日志，debughelper 可以加快我們調試時日志的檢索速度
復制代碼
復制代碼
在 Startup 中
復制代碼
public void Configure(IApplicationBuilder app, IHostingEnvironment env)
{
//省略了其他配置
//全局的 HttpContext
app.UseGlobalHttpContext();
//省略了其他配置
LogManager.Configuration = new XmlLoggingConfiguration(Path.Combine(env.ContentRootPath, "nlog.config"));
LogManager.Configuration.Variables["root"] = env.ContentRootPath;
LogManager.Configuration.Variables["connectionString"] = Configuration.GetConnectionString("DefaultConnection");
}
復制代碼
自定義字段都是通過 LayoutRenderer 實現，由於自定義字段有很多，這里只列出了一個開始時間是如何查詢的，這個時間是在我們注冊的第一個中間件執行 Invoke 方法的時候寫進 HttpContext.Items 的
復制代碼
[LayoutRenderer("apiinsight-start")]
public class StartApiInsightRenderer : LayoutRenderer
{
protected override void Append(StringBuilder builder, LogEventInfo logEvent)
{
var httpContext = HttpContextProvider.Current;
if (httpContext == null)
{
return;
}
var _apiInsightsKeys = httpContext.RequestServices.GetService
if (httpContext != null)
{
if (httpContext.Items.TryGetValue(_apiInsightsKeys.StartTimeName, out var start) == true)
{
builder.Append(start.ToString());
}
}
}
}
復制代碼
NLog 規則，很容易理解日志統計只記錄 Cheers 命名空間下的日志
復制代碼
<!--忽略的日志-->
<logger name="Microsoft.*" minlevel="Trace" writeTo="blackhole" final="true" />
public ApiInsightMiddleware(RequestDelegate next, IServiceProvider serviceProvider, ILogger<ApiInsightMiddleware> logger)
{
_next = next;
_serverProvider = serviceProvider;
_apiInsightsKeys = _serverProvider.GetService<IApiInsightsKeys>();
_logger = logger;
}
public async Task Invoke(HttpContext httpContext)
{
_httpContext = httpContext;
var flag = SetValues();
await _next(httpContext);
if (flag == true)
{
ApiInsight();
}
}
//省略了其他的代碼
}
復制代碼
很好理解，在執行下一個中間件之前調用 SetValues 開始計時，下一個中間件執行成功開始統計並寫入日志（或者忽略不寫）。現在他是 asp.net core mvc 的第一個中間件了，好處就是更符合這個中間件本身的所做的事情了，但是帶來的問題就是 httpContext.RequestService 是 null ，因為 RequestService 是在 RequestServicesContainerMiddleware 這個中間件寫進去的，在者其實很多地方我們都需要 HttpContext ，並且目前微軟還沒有給我們定義一個靜態的 HttpContext。
靜態的 HttpContext
HttpContext 是通過單例 IHttpContextAccessor 提供的，當 HttpContext 創建的時候就會賦值給他，當請求到達中間件這個管道的時候，HttpContext 就已經存在於 IHttpContextAccessor 了，並且和 Invoke 參數列表中的 HttpContext 是一致的（同一個請求中），問題在於 RequestServicesContainerMiddleware 這個中間件沒有執行就沒有容器，並且很多時候我們都要用到容器，所以就模仿源碼在這里都加進去了。
復制代碼
public static class HttpContextProvider
{
private static IHttpContextAccessor _accessor;
private static IServiceScopeFactory _serviceScopeFactory;
public static Microsoft.AspNetCore.Http.HttpContext Current
{
get
{
var context = _accessor?.HttpContext;
if (context != null)
{
var replacementFeature = new RequestServicesFeature(_serviceScopeFactory);
context.Features.Set<IServiceProvidersFeature>(replacementFeature);
return context;
}
return null;
}
}
internal static void ConfigureAccessor(IHttpContextAccessor accessor, IServiceScopeFactory serviceScopeFactory)
{
_accessor = accessor;
_serviceScopeFactory = serviceScopeFactory;
}
}
public static class HttpContextExtenstion
{
public static void AddHttpContextAccessor(this IServiceCollection services)
{
services.AddSingleton<IHttpContextAccessor, HttpContextAccessor>();
}
public static IApplicationBuilder UseGlobalHttpContext(this IApplicationBuilder app)
{
var httpContextAccessor = app.ApplicationServices.GetRequiredService<IHttpContextAccessor>();
var serviceScopeFactory = app.ApplicationServices.GetRequiredService<IServiceScopeFactory>();
HttpContextProvider.ConfigureAccessor(httpContextAccessor, serviceScopeFactory);
return app;
}
}
復制代碼
我們只需要在 Startup 中使用 app.UseGlobalHttpContext(); 就可以在程序的任何地方得到 HttpContext 和容器了，肯定會有人說為什么不通過構造函數來獲取我們想要的注入呢，因為有些第三方框架或這某些地方我們不能使用容器獲取服務，比如這里 NLog 的自定義字段使用的 LayoutRenderer 就無法通過構造器得到我們想要的服務。
第一個中間件
在 Startup 的 Configure 方法中目前還沒發現如何注冊第一個中間件，因為 Configure 方法始終是在 IStartupFilter 這個接口之后執行的，這也提供了我們讓自己的中間件成為第一個中間件的可能。可能這樣做並不是特別有必要，甚至是沒有意義的，但是實現的過程確實很有意思的。這里在 Startup 中的 方法 ConfigureService 注冊我們的中間件。
public void ConfigureServices(IServiceCollection services)
{
services.AddApiInsights();
services.AddMvc();
}
具體的
復制代碼
public static class ApiInsightsServiceCollectionExtensions
{
static readonly string stopWatchName = "stopwatch";
static readonly string startTimeName = "start";
/// <summary>
/// 注冊和 API 監控相關的服務，中間件
/// </summary>
/// <param name="services"></param>
public static void AddApiInsights(this IServiceCollection services)
{
services.AddSingleton<IApiInsightsKeys>(
new ApiInsightsKeys(stopWatchName, startTimeName)
);
services.FirstRegister<IStartupFilter, RequestApiInsightBeginStartupFilter>(ServiceCollectionServiceExtensions.AddTransient<IStartupFilter, RequestApiInsightBeginStartupFilter>);
services.AddSingleton<IRequestIsAuthenticate, DefaultRequestIsAuthenticate>();
}
}
復制代碼
這里注冊了三個服務
IApiInsightsKeys
定義了存儲在 HttpContext.Item 中的鍵值對的名稱
public interface IApiInsightsKeys
{
string StopWatchName { get; }
string StartTimeName { get; }
}
IRequestIsAuthenticate
復制代碼
///
/// 驗證請求用戶是否已經認證
///
public interface IRequestIsAuthenticate
{
///
/// 返回已經認證的 scheme
///
///
Task
///
/// 返回已經認證的 用戶名
///
///
Task
}
復制代碼
就驗證而言可能不同的開發者使用的是不一樣的驗證方式，可能是基於 Asp.Net Core Authentication 中間件的認證方式，也可能是其他的比如自定義的 token，或者有一個單點登錄的服務器，又或者是 session，其實 Asp.Net Core 的 Authentication 中間件也可以幫我們實現基於 restful 的token 認證。所以就把它定義出來了，並且默認的實現就是基於 Authentication 這個中間件的。
IStartupFilter
看到他是一個非常特殊的方式來注冊的，自定義的 FirstRegister 這個方法，實際上 Asp.Net Core 內置有多個 IStartup 這樣的服務，並且都是在 Startup 的 Configure 之前執行的，所以這里一定要用這個服務來讓我們的中間件成為第一個中間件。FirstRegister 代碼也很容易理解，由於在宿主啟動之前，內部注冊了多個 IStartup，並且最后會按先后順序配置 IApplicationBuilder，所以我們只能讓第一個 StartupFilter 的 IApplicationBuilder 就注冊我們的中間件，通過改動 ServiceCollection 中服務的順序可以實現。雖然不是很有必要，但是可以從中觀察的 Startup 的 Configure方法 以及 接口StartupFilter （還有 IHostingStartup ）的執行順序。
復制代碼
public class RequestApiInsightBeginStartupFilter : IStartupFilter
{
public Action
{
return builder =>
{
builder.UseMiddleware
next(builder);
};
}
}
復制代碼
忽略的方法
[AttributeUsage(AttributeTargets.Method, AllowMultiple = false, Inherited = true)]
public class NoInsightAttribute : Attribute
{
}
在 ApiInsight 方法中會調用 IsIgnore 檢測該方法是否打了標簽 NoInsightAttribute，如果是那就忽略該方法，這里建議使用特性路由，原因有兩點，第一特性路由不需要使用 IActionSelector 接口重新查找匹配的方法，第二，在 restful api 中，結合特性路由和 HttpMethodAttribute 標簽可以使方法更簡潔，相同的接口名稱通過不同的請求方式達到不同的目的
復制代碼
private bool IsIgnore()
{
var actionDescriptor = GetSelectedActionDescriptor() as ControllerActionDescriptor;
if (actionDescriptor == null)
{
return false;
}
else
{
var noInsight = actionDescriptor.MethodInfo.GetCustomAttribute
return noInsight != null;
}
}
復制代碼
程序地址:
https://github.com/cheesebar/ApiInsights