用NetCore + ReactJS 实现一个前后端分离的网站 (5) 日志&全局异常处理 - log4net & AOP切面编程

1. 前言

日志始终是跟踪与调试程序的最佳手段，因为调试难以溯及既往，而日志则能忠实地记录下曾经发生过的事情。

2. log4net

这个工具大家再熟悉不过了，这里简单介绍一下。

2.1 添加以下引用

• log4net
• Microsoft.Extensions.Logging.Log4Net.AspNetCore

2.2. 在根目录添加配置文件log4net.config

配置文件

<?xml version="1.0" encoding="utf-8"?>
<log4net>
  <appender name="RollingAppender" type="log4net.Appender.RollingFileAppender">
    <!--指定日志文件保存的目录-->
    <file value="log/"/>
    <!--追加日志内容-->
    <appendToFile value="true"/>
    <!--可以为：Once|Size|Date|Composite-->
    <!--Compoosite为Size和Date的组合-->
    <rollingStyle value="Composite"/>
    <!--设置为true，当前最新日志文件名永远为file字节中的名字-->
    <staticLogFileName value="false"/>
    <!--当备份文件时，备份文件的名称及后缀名-->
    <datePattern value="yyyyMMdd'.txt'"/>
    <!--日志最大个数-->
    <!--rollingStyle节点为Size时，只能有value个日志-->
    <!--rollingStyle节点为Composie时，每天有value个日志-->
    <maxSizeRollBackups value="20"/>
    <!--可用的单位：KB|MB|GB-->
    <maximumFileSize value="5MB"/>
    <filter type="log4net.Filter.LevelRangeFilter">
      <param name="LevelMin" value="ALL"/>
      <param name="LevelMax" value="FATAL"/>
    </filter>
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline"/>
    </layout>
  </appender>
  <root>
    <priority value="ALL"/>
    <level value="ALL"/>
    <appender-ref ref="RollingAppender"/>
  </root>
</log4net>

2.3. 添加服务

Program.cs

#region Log
builder.WebHost.ConfigureLogging((context, loggingBuilder) =>
{
    loggingBuilder.AddFilter("System", LogLevel.Warning);
    loggingBuilder.AddFilter("Microsoft", LogLevel.Warning);

    var path = Path.Combine(Environment.CurrentDirectory, "log4net.config");
    loggingBuilder.AddLog4Net(path);
});
#endregion

2.4. 通过构造函数注入

NovelController.cs

// 通过构造函数注入依赖
public NovelController(INovelService novelService, ILogger<NovelController> logger)
{
    _novelService = novelService;
    _logger = logger;
}

// 其他代码
[HttpGet("{id}")]
[ApiAuthorize]
public async Task<ResponseModel<Novel>> Get(int id)
{
    _logger.LogInformation($"Get novel, id = {id}, current user: {UserID}");
    var novel = await _novelService.SelectAsync(x => x.ID == id);
    return new ResponseModel<Novel>().Ok(novel);
}
// 其他代码

2.5. 输出到日志文件

---

AOP切面编程这个概念其实和中间件很像，只不过中间件处理的是请求，而这个是通过过滤器(Filter)和拦截器(Interceptor)为服务层服务。

3. 过滤器

3.1. 添加实现

LogFilter.cs

using Microsoft.AspNetCore.Mvc.Filters;
using NovelTogether.Core.API.Utils;
using System.Text.Encodings.Web;
using System.Text.Json;
using System.Text.Unicode;

namespace NovelTogether.Core.API.Filters
{
    public class LogFilter : IActionFilter
    {
        private readonly ILogger<LogFilter> _logger;

        public LogFilter(ILogger<LogFilter> logger)
        {
            _logger = logger;
        }

        public void OnActionExecuted(ActionExecutedContext context)
        {
            var option = new JsonSerializerOptions()
            {
                Encoder = JavaScriptEncoder.Create(UnicodeRanges.All)
            };

            var result = "void";
            var uniqueId = context.HttpContext.Items[Consts.UNIQUE_ID].ObjToString();
            if (context.Result != null)
                result = JsonSerializer.Serialize(((Microsoft.AspNetCore.Mvc.ObjectResult)context.Result).Value, option);
            _logger.LogInformation($"Action Executed\r\n唯一标识: {uniqueId}\r\n结果: {result} ");
        }

        public void OnActionExecuting(ActionExecutingContext context)
        {
            var action = (Microsoft.AspNetCore.Mvc.Controllers.ControllerActionDescriptor)context.ActionDescriptor;
            var controllerName = action.ControllerTypeInfo.FullName;
            var actionName = action.ActionName;

            var uniqueId = Guid.NewGuid().ToString("N");
            context.HttpContext.Items.Add(Consts.UNIQUE_ID, uniqueId);
            _logger.LogInformation($"Action Executing\r\n唯一标识: {uniqueId}\r\n方法名: {controllerName}.{actionName}\r\n参数: {JsonSerializer.Serialize(context.ActionArguments)}");
        }
    }
}

3.2. 添加服务

服务

builder.Services.AddControllers(option =>
{
    option.Filters.Add(typeof(LogFilter));
});

3.3. 输出到日志文件

4. 拦截器

相比过滤器作用在Controller上，拦截器是作用在Service层或者说接口层。

4.1. 添加实现

这里参考了@wswind的这篇文章，稍修改了下。

AsyncInterceptorBase.cs

using System;
using System.Reflection;
using System.Runtime.CompilerServices;
using System.Threading.Tasks;
using Castle.DynamicProxy;

namespace NovelTogether.Core.API.AOP
{
    //inspired by : https://stackoverflow.com/a/39784559/7726468
    public abstract class AsyncInterceptorBase : IInterceptor
    {
        public AsyncInterceptorBase()
        {
        }

        public void Intercept(IInvocation invocation)
        {
            BeforeProceed(invocation);
            invocation.Proceed();
            if (IsAsyncMethod(invocation.MethodInvocationTarget))
            {
                // 关键实现语句
                invocation.ReturnValue = InterceptAsync((dynamic)invocation.ReturnValue, invocation);
            }
            else
            {
                AfterProceedSync(invocation);
            }
        }

        private bool CheckMethodReturnTypeIsTaskType(MethodInfo method)
        {
            var methodReturnType = method.ReturnType;
            if (methodReturnType.IsGenericType)
            {
                if (methodReturnType.GetGenericTypeDefinition() == typeof(Task<>) ||
                    methodReturnType.GetGenericTypeDefinition() == typeof(ValueTask<>))
                    return true;
            }
            else
            {
                if (methodReturnType == typeof(Task) ||
                    methodReturnType == typeof(ValueTask))
                    return true;
            }
            return false;
        }

        private bool IsAsyncMethod(MethodInfo method)
        {
            bool isDefAsync = Attribute.IsDefined(method, typeof(AsyncStateMachineAttribute), false);
            bool isTaskType = CheckMethodReturnTypeIsTaskType(method);
            bool isAsync = isDefAsync && isTaskType;

            return isAsync;
        }

        protected object ProceedAsyncResult { get; set; }


        private async Task InterceptAsync(Task task, IInvocation invocation)
        {
            await task.ConfigureAwait(false);
            await AfterProceedAsync(invocation);
        }

        private async Task<TResult> InterceptAsync<TResult>(Task<TResult> task, IInvocation invocation)
        {
            ProceedAsyncResult = await task.ConfigureAwait(false);
            await AfterProceedAsync(invocation, ProceedAsyncResult);
            return (TResult)ProceedAsyncResult;
        }

        private async ValueTask InterceptAsync(ValueTask task, IInvocation invocation)
        {
            await task.ConfigureAwait(false);
            await AfterProceedAsync(invocation, false);
        }

        private async ValueTask<TResult> InterceptAsync<TResult>(ValueTask<TResult> task, IInvocation invocation)
        {
            ProceedAsyncResult = await task.ConfigureAwait(false);
            await AfterProceedAsync(invocation, true);
            return (TResult)ProceedAsyncResult;
        }

        protected virtual void BeforeProceed(IInvocation invocation) { }

        protected virtual void AfterProceedSync(IInvocation invocation) { }

        protected virtual Task AfterProceedAsync(IInvocation invocation)
        {
            return Task.CompletedTask;
        }

        protected virtual Task AfterProceedAsync<TResult>(IInvocation invocation, TResult returnValue)
        {
            return Task.CompletedTask;
        }
    }
}

LogInterceptor.cs

using Castle.DynamicProxy;
using System.Text.Json;

namespace NovelTogether.Core.API.AOP
{
    public class LogInterceptor : AsyncInterceptorBase
    {
        private readonly ILogger<LogInterceptor> _logger;

        public LogInterceptor(ILogger<LogInterceptor> logger)
        {
            _logger = logger;
        }

        protected override void BeforeProceed(IInvocation invocation)
        {
            // 执行方法前
            var methodPreExecuting = $"Method Pre Executing\r\nMethod: {invocation.Method.Name}\r\nParameters: {string.Join(", ", invocation.Arguments.Select(x => (x ?? "").ToString()).ToArray())}";
            _logger.LogInformation(methodPreExecuting);
        }

        protected override void AfterProceedSync(IInvocation invocation)
        {
            // 执行方法后
            var methodAfterExecuting = $"Method After Executing\r\nResult:{invocation.ReturnValue}";
            _logger.LogInformation(methodAfterExecuting);
        }

        protected override Task AfterProceedAsync<TResult>(IInvocation invocation, TResult returnValue)
        {
            // 执行方法后
            var methodAfterExecuting = $"Method After Executing\r\nResult:{JsonSerializer.Serialize(returnValue)}";
            _logger.LogInformation(methodAfterExecuting);

            return Task.CompletedTask;
        }
    }
}

4.2. 添加服务

Program.cs

// 其他代码
containerBuilder.RegisterType<LogInterceptor>();

// 其他代码
var assembly = Assembly.LoadFile(assemblyPath);
containerBuilder.RegisterAssemblyTypes(assembly)
    .AsImplementedInterfaces()
    .InstancePerLifetimeScope()
    .EnableInterfaceInterceptors().InterceptedBy(typeof(LogInterceptor));

// 其他代码

4.3. 输出到日志文件

从图中可以看到Filter->Controller->Interceptor这样一个顺序。
这里还有个问题没解决，就是因为服务层的参数都是Expression类型，而不是普通的int或者object类型，所以取出来的参数看着很奇怪。

4.4. 序列化的问题

可以看到日志中的中文都被转义了，这是NetCore内置的JsonSerializer的问题，需要在执行Serialize的时候传一个参数。

查看代码

var option = new JsonSerializerOptions()
{
    Encoder = JavaScriptEncoder.Create(UnicodeRanges.All)
};

JsonSerializer.Serialize(returnValue, option);

结果

5. 全局异常处理

本来这一节的专题是日志，不过同样是用到了Filter，顺便说下全局的异常处理。

5.1. 代码实现

GlobalExceptionFilter.cs

using Azure;
using Microsoft.AspNetCore.Mvc;
using Microsoft.AspNetCore.Mvc.Filters;
using Newtonsoft.Json;
using NovelTogether.Core.API.Utils;
using NovelTogether.Core.Model.ViewModels;

namespace NovelTogether.Core.API.Filters
{
    public class GlobalExceptionFilter : IExceptionFilter
    {
        private readonly ILogger<GlobalExceptionFilter> _logger;

        public GlobalExceptionFilter(ILogger<GlobalExceptionFilter> logger)
        {
            _logger = logger;
        }

        public void OnException(ExceptionContext context)
        {
            // 如果异常没有被处理则进行处理
            if (context.ExceptionHandled == false)
            {
                //写入日志
                _logger.LogError(context.Exception, $"Path: {context.HttpContext.Request.Path}, User id: {context.HttpContext.Items[Consts.USER_ID]}");

                context.Result = new JsonResult(new ResponseModel<string>().Failed(500, "内部错误，请联系管理员。"));
            }
            // 设置为true，表示异常已经被处理了
            context.ExceptionHandled = true;
        }
    }
}

5.2. 添加服务

Program.cs

builder.Services.AddControllers(option =>
{
    option.Filters.Add(typeof(LogFilter));
    option.Filters.Add(typeof(GlobalExceptionFilter));
});

5.3. 输出异常到日志文件。

6. 总结

日志和全局异常处理就简单地通过过滤器和拦截器来实现了，下一节说一说缓存的问题。