一、业务需求描述
因前端接口请求响应较慢,故想在后端也记录一下接口或中间件请求耗时,通过全局记录,对部分较慢的接口进行优化
二、RequestTimeActionFilter
使用ActionFilter记录控制器接口(Action)执行耗时,步骤:
1.在执行【OnActionExecuting】时,创建一个【stopWatch】计时器对象,并将该对象存在【HttpContext】中。
2.在执行【OnActionExecuted】时,获取【HttpContext】中执行【OnActionExecuting】时存储的【stopWatch】计时器对象,并获取该对象中的【ElapsedMilliseconds 】属性,获取此次请求耗时。
3.创建一个【RequestTimeActionFilter.cs】类,并添加以下代码:
using Microsoft.AspNetCore.Mvc.Filters;
using System.Diagnostics;
namespace WebApp01.Filters
{
public class RequestTimeActionFilter : IActionFilter
{
private readonly string key = "_responseKey";
private readonly ILogger<RequestTimeActionFilter> _logger;
public RequestTimeActionFilter(ILogger<RequestTimeActionFilter> logger)
{
this._logger = logger;
}
public void OnActionExecuted(ActionExecutedContext context)
{
//日志记录
WriteLog(context);
}
public void OnActionExecuting(ActionExecutingContext context)
{
var stopWatch = new Stopwatch();
context.HttpContext.Items[key] = stopWatch;
stopWatch.Start();
}
/// <summary>
/// 日志记录
/// </summary>
/// <param name="context"></param>
private void WriteLog(ActionExecutedContext context)
{
//获取存在当前请求中的stopwatch对象
Stopwatch stopwatch = (Stopwatch)context.HttpContext.Items[key];
//获取由当前实例测量的总运行时间(以毫秒为单位)。
//Gets the total elapsed time measured by the current instance, in milliseconds.
double currentSeconds = stopwatch.ElapsedMilliseconds / 1000.0;
string userName = context.HttpContext.User.Identity?.Name;
//获取控制器相关参数
//string controllerName = context.ActionDescriptor.RouteValues["controller"];
//string actionName = context.ActionDescriptor.RouteValues["action"];
//string accessPath = $"/api/{controllerName}/{actionName}";
//当前访问的路径
string accessPath = context.HttpContext.Request.Path;
string res = $"{
userName}({
DateTime.Now})访问{
accessPath} 接口耗时:【{
currentSeconds}】秒";
_logger.LogInformation(res);
}
}
}
4.在【Program.cs】中注入Filter
builder.Services.AddControllers(options =>
{
options.Filters.Add<RequestTimeActionFilter>();//接口请求记录中间件
});
三、RequestTimeMiddleware
使用Middleware记录中间件执行耗时,步骤:
1.在执行【OnActionExecuting】时,创建一个【stopWatch】计时器对象,并将该对象存在【HttpContext】中。
2.在执行【OnActionExecuted】时,获取【HttpContext】中执行【OnActionExecuting】时存储的【stopWatch】计时器对象,并获取该对象中的【ElapsedMilliseconds 】属性,获取此次请求耗时。
3.创建一个【RequestTimeMiddleware.cs】类,并添加以下代码:
using System.Diagnostics;
namespace WebApp01.Middlewares
{
public class RequestTimeMiddleware
{
private readonly RequestDelegate _next;
private readonly ILogger<RequestTimeMiddleware> _logger;
public RequestTimeMiddleware(RequestDelegate next, ILogger<RequestTimeMiddleware> logger)
{
_next = next;
this._logger = logger;
}
public Task InvokeAsync(HttpContext context)
{
//创建计时器对象,并开启计时
var watch = new Stopwatch();
watch.Start();
context.Response.OnStarting(() => {
// 停止计时
watch.Stop();
double currentSeconds = watch.ElapsedMilliseconds / 1000.0;
WriteLog(context, currentSeconds);
return Task.CompletedTask;
});
// 执行下一个中间件
return this._next(context);
}
/// <summary>
/// 日志记录
/// </summary>
/// <param name="context"></param>
private void WriteLog(HttpContext context, double currentSeconds)
{
string userName = context.Request.HttpContext.User.Identity?.Name;
string accessPath = context.Request.Path;
string res = $"{
userName}({
DateTime.Now}) 访问路径:{
accessPath},RequestTimeMiddleware中间件执行耗时:【{
currentSeconds}】秒";
_logger.LogInformation(res);
}
}
}
4.在【Program.cs】中注入Middleware(在所有Middleware中间件之前注入,这样就会监控到执行完所有中间件后返回前端的耗时)
app.UseMiddleware<RequestTimeMiddleware>();
四、测试
1.在创建的WebApi项目中默认【WeatherForecastController.cs】控制器中调整以下代码:
(1)【GetWeatherForecast】为默认的接口,返回的是一个json。
(2)【GetSleepWeatherForecast】是新增的接口,在当前线程中sleep 1秒钟,用于测试Filter和中间件是否有正确记录
[ApiController]
[Route("api/[controller]/[action]")]
public class WeatherForecastController : ControllerBase
{
private static readonly string[] Summaries = new[]
{
"Freezing", "Bracing", "Chilly", "Cool", "Mild", "Warm", "Balmy", "Hot", "Sweltering", "Scorching"
};
private readonly ILogger<WeatherForecastController> _logger;
public WeatherForecastController(ILogger<WeatherForecastController> logger)
{
_logger = logger;
}
[HttpGet(Name = "GetWeatherForecast")]
public IEnumerable<WeatherForecast> Get()
{
return Enumerable.Range(1, 5).Select(index => new WeatherForecast
{
Date = DateTime.Now.AddDays(index),
TemperatureC = Random.Shared.Next(-20, 55),
Summary = Summaries[Random.Shared.Next(Summaries.Length)]
})
.ToArray();
}
[HttpGet(Name = "GetSleepWeatherForecast")]
public IEnumerable<WeatherForecast> GetSleep()
{
Thread.Sleep(1000);
return Enumerable.Range(1, 5).Select(index => new WeatherForecast
{
Date = DateTime.Now.AddDays(index),
TemperatureC = Random.Shared.Next(-20, 55),
Summary = Summaries[Random.Shared.Next(Summaries.Length)]
})
.ToArray();
}
}
2.分别执行【swagger】中的【Get】和【GetSleep】接口,执行结果如下:
(1)“圈1”记录的是swagger的【index.html】和【swagger.json】的请求耗时
(2)“圈2”记录的是控制器【Get】接口在filter和middleware中的耗时。
(2)“圈3”记录的是控制器【GetSleep】接口在filter和middleware中的耗时。