【部门技术分享】如何记录函数Enter，Leave以及函数执行时间日志（.NET AOP）

前言

在平时的开发过程中，也许我们需要在函数的入口和出口打印日志，以及记录函数的执行时间。 如何使用AOP的理念来完成这一个需求呢

Abp 动态代理

在ABP VNext中有许多的概念，比如UOW， Audit都是利用AOP来在函数中编织自己需要的代码，我们可以使用这一概念来完成。 该方法只能编织 virutal 方法

1. 定义我们需要的Attribute

    [AttributeUsage(AttributeTargets.Method | AttributeTargets.Class | AttributeTargets.Interface)]
    public class MethodTraceAttribute : Attribute
    {
        public bool WithPerformance { get; set; }

        /// <summary>
        /// Default: false.
        /// </summary>
        public bool IsDisabled { get; set; }

        public MethodTraceAttribute()
        {
            WithPerformance = false;
        }
    }

以及接口

    /// <summary>
    /// 如果类从该接口继承，该类所有的virtual方法都会被编织，只有virtual的方法才会被编织
    /// </summary>
    public interface IMethodTraceEnabled
    {
    }

2. 定义编织函数

    public class MethodTraceInterceptor : AbpInterceptor, ITransientDependency
    {
        protected ILogger<MethodTraceInterceptor> Logger { get; }

        public MethodTraceInterceptor(ILogger<MethodTraceInterceptor> logger)
        {
            Logger = logger;
        }

        public async override Task InterceptAsync(IAbpMethodInvocation invocation)
        {
            if (!MethodTraceHelper.IsMethodTraceMethod(invocation.Method, out var methodTraceAttribute))
            {
                await invocation.ProceedAsync();
                return;
            }

            Logger.LogDebug($"Enter {invocation.Method.Name}");


            // 记录方法开始
            if (methodTraceAttribute.WithPerformance)
            {
                var watch = new Stopwatch();
                watch.Start();

                await invocation.ProceedAsync();

                watch.Stop();
                
                //结束计时
                //获取当前实例测量得出的总运行时间（以毫秒为单位）
                string time = watch.ElapsedMilliseconds.ToString();
                Logger.LogDebug($"The fuction {invocation.Method.Name} took {time} to execute");
            }else
            {
                await invocation.ProceedAsync();
            }

            // 记录方法结束
            Logger.LogDebug($"Leave {invocation.Method.Name}");
        }
    }

3. 定义辅助类来判断方法，类是否有相应的属性以及是否从IMethodTraceEnabled继承

public static class MethodTraceHelper
    {
        public static bool IsUnitOfWorkType(TypeInfo implementationType)
        {
            //Explicitly defined UnitOfWorkAttribute
            if (HasMethodTraceAttribute(implementationType) || AnyMethodHasMethodTraceAttribute(implementationType))
            {
                return true;
            }

            //Conventional classes
            if (typeof(IMethodTraceEnabled).GetTypeInfo().IsAssignableFrom(implementationType))
            {
                return true;
            }

            return false;
        }

        public static bool IsMethodTraceMethod([NotNull] MethodInfo methodInfo, [CanBeNull] out MethodTraceAttribute unitOfWorkAttribute)
        {
            Check.NotNull(methodInfo, nameof(methodInfo));

            //Method declaration
            var attrs = methodInfo.GetCustomAttributes(true).OfType<MethodTraceAttribute>().ToArray();
            if (attrs.Any())
            {
                unitOfWorkAttribute = attrs.First();
                return !unitOfWorkAttribute.IsDisabled;
            }

            if (methodInfo.DeclaringType != null)
            {
                //Class declaration
                attrs = methodInfo.DeclaringType.GetTypeInfo().GetCustomAttributes(true).OfType<MethodTraceAttribute>().ToArray();
                if (attrs.Any())
                {
                    unitOfWorkAttribute = attrs.First();
                    return !unitOfWorkAttribute.IsDisabled;
                }

                //Conventional classes
                if (typeof(IMethodTraceEnabled).GetTypeInfo().IsAssignableFrom(methodInfo.DeclaringType))
                {
                    unitOfWorkAttribute = null;
                    return true;
                }
            }

            unitOfWorkAttribute = null;
            return false;
        }

        public static MethodTraceAttribute GetMethodTraceAttributeOrNull(MethodInfo methodInfo)
        {
            var attrs = methodInfo.GetCustomAttributes(true).OfType<MethodTraceAttribute>().ToArray();
            if (attrs.Length > 0)
            {
                return attrs[0];
            }

            attrs = methodInfo.DeclaringType.GetTypeInfo().GetCustomAttributes(true).OfType<MethodTraceAttribute>().ToArray();
            if (attrs.Length > 0)
            {
                return attrs[0];
            }

            return null;
        }

        private static bool AnyMethodHasMethodTraceAttribute(TypeInfo implementationType)
        {
            return implementationType
                .GetMethods(BindingFlags.Instance | BindingFlags.Public | BindingFlags.NonPublic)
                .Any(HasMethodTraceAttribute); 
        }

        private static bool HasMethodTraceAttribute(MemberInfo methodInfo)
        {
            return methodInfo.IsDefined(typeof(MethodTraceAttribute), true);
        }
    }

4. 定义module，并注册我们的编织函数

    /// <summary>
    /// 动态代理的特性，决定只有virtual的方法才会被编织
    /// </summary>
    public static class MethodTraceInterceptorRegistrar
    {
        public static void RegisterIfNeeded(IOnServiceRegistredContext context)
        {
            if (ShouldIntercept(context.ImplementationType))
            {
                context.Interceptors.TryAdd<MethodTraceInterceptor>();
            }
        }

        private static bool ShouldIntercept(Type type)
        {
            return !DynamicProxyIgnoreTypes.Contains(type) && MethodTraceHelper.IsUnitOfWorkType(type.GetTypeInfo());
        }
    }

和

    public class UihAbpLogExtensionModule : AbpModule
    {
        public override void PreConfigureServices(ServiceConfigurationContext context)
        {
            context.Services.OnRegistred(MethodTraceInterceptorRegistrar.RegisterIfNeeded);
        }
    }

5. 接下来看如何使用

首先在你的模块中依赖 typeof(UihAbpLogExtensionModule),

    [MethodTrace(WithPerformance = false)]
    public class ClassWithLogTraceAttribute : ITransientDependency
    {
        private readonly ILogger<ClassWithLogTraceAttribute> _logger;

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

        public async Task PublicMethodTestAsync()
        {
            await PrivateMethodTestAsync();

            DisableMethodTest();
        }

        private async Task PrivateMethodTestAsync()
        {
            await Task.Delay(5);
        }

        [MethodTrace(IsDisabled = true)]
        private void DisableMethodTest()
        {

        }

    }

    public class ClassWithoutMethodTraceAttribute : ITransientDependency
    {
        [MethodTrace]
        public async Task PublicMethodTestAsync()
        {
            await PrivateMethodTest();

            DisableMethodTest();
        }

        [MethodTrace(WithPerformance = true)]
        private async Task PrivateMethodTest()
        {
            await Task.Delay(5);
        }

        [MethodTrace(IsDisabled = true)]
        private void DisableMethodTest()
        {

        }
    }

使用Fody来进行编织，在Abp VNext大量的使用 ConfigureAwait 来编织异步方法。Fody的原理为在IL代码中的插入相关的代码来完成AOP，我们也可以使用这个概念来完成 ，测试代码

1. 引用相应的库，定义了tracerserilog.props, 在你的工程中进行引入

<Project>
  <ItemGroup>
      <PackageReference Include="Tracer.Serilog.Fody" Version="3.3.1" PrivateAssets="All" />
      <PackageReference Include="Fody" Version="6.3.0">
        <PrivateAssets>All</PrivateAssets>
        <IncludeAssets>runtime; build; native; contentfiles; analyzers</IncludeAssets>
      </PackageReference>
  </ItemGroup>
</Project>

2. 定义 FodyWeavers.xml, 编织了Public类的public，private方法。配置的语法从这里找 https://github.com/csnemes/tracer，这里可以做笔记精细化的配置

<Weavers xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:noNamespaceSchemaLocation="FodyWeavers.xsd">
  <Tracer adapterAssembly="Tracer.Serilog" logManager="Tracer.Serilog.Adapters.LogManagerAdapter" logger="Tracer.Serilog.Adapters.LoggerAdapter" staticLogger="Tracer.Serilog.Log" traceConstructors="false" traceProperties="false">
    <TraceOn class="public" method="public" />
    <TraceOn class="public" method="private" />
  </Tracer>
</Weavers>

3. 编织的log 级别为Trace，因此我们需要设置对相应的日志级别。 编译后的dll进行反编译结果

4. 执行的结果

By ruifei