使用NLog给Asp.Net Core做请求监控的方法

为了减少由于单个请求挂掉而拖垮整站的情况发生，给所有请求做统计是一个不错的解决方法，通过观察哪些请求的耗时比较长，我们就可以找到对应的接口、代码、数据表，做有针对性的优化可以提高效率。在 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

然后在 global 中注册

public class delegatinghandler1 : delegatinghandler
  {
    protected override async task<httpresponsemessage> sendasync(httprequestmessage request, cancellationtoken cancellationtoken)
    {
      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<httpresponsemessage> sendasync(httprequestmessage request, cancellationtoken cancellationtoken)
    {
      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<httpresponsemessage> sendasync(httprequestmessage request, cancellationtoken cancellationtoken)
    {
      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;
    }
  }

修改一下 valuescontroller

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());
    }
  }

启动后输入路径 /api/values，我们可以在vs 的输出栏看到下面这些内容

public class valuescontroller : apicontroller
  {
    // get api/values
    public ienumerable<string> get()
    {
      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<httpresponsemessage> sendasync(httprequestmessage request, cancellationtoken cancellationtoken)
    {
      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 可以加快我们调试时日志的检索速度

<targets>
  <!--黑洞 忽略的日志-->
  <target xsi:type="null"
      name="blackhole" />
  <!--文件日志-->
  <target xsi:type="file"
    name="debughelper"
    filename="${var:root}\logs\debug_helper.log"
    layout="${longdate}|${event-properties:item=eventid.id}|${logger}|${uppercase:${level}}|${message} ${exception}" />
  <!--apiinsight api 统计-->
  <target name="apiinsight" xsi:type="database"
       dbprovider="mysql.data.mysqlclient.mysqlconnection, mysql.data"
       connectionstring="${var:connectionstring}"
       >
  </target>
  <!--日志-->
  <target name="log" xsi:type="database"
     dbprovider="mysql.data.mysqlclient.mysqlconnection, mysql.data"
     connectionstring="${var:connectionstring}"
       >
  </target>
 </targets>

在 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<iapiinsightskeys>();

      if (httpcontext != null)
      {
        if (httpcontext.items.trygetvalue(_apiinsightskeys.starttimename, out var start) == true)
        {
          builder.append(start.tostring());
        }
      }
    }
  }

nlog 规则，很容易理解日志统计只记录 cheers 命名空间下的日志

<rules>
  <!--需要记录的日志-->
  <logger name="cheers.*" minlevel="trace" writeto="apiinsight" />
  <logger name="webapp.*" minlevel="info" writeto="log" />
  <logger name="*" minlevel="trace" maxlevel="debug" writeto="debughelper" />

  <!--忽略的日志-->
  <logger name="microsoft.*" minlevel="trace" writeto="blackhole" final="true" />
 </rules>

核心 apiinsightmiddleware 中间件

public class apiinsightmiddleware
  {
    private readonly requestdelegate _next;
    private readonly iserviceprovider _serverprovider;
    private readonly iapiinsightskeys _apiinsightskeys;
    private readonly ilogger<apiinsightmiddleware> _logger;
    private httpcontext _httpcontext;

    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

/// <summary>
  ///   验证请求用户是否已经认证
  /// </summary>
  public interface irequestisauthenticate
  {
    /// <summary>
    ///   返回已经认证的 scheme
    /// </summary>
    /// <returns></returns>
    task<string> isauthenticateasync();
    /// <summary>
    ///   返回已经认证的 用户名
    /// </summary>
    /// <returns></returns>
    task<string> authenticatedusername();
  }

就验证而言可能不同的开发者使用的是不一样的验证方式，可能是基于 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<iapplicationbuilder> configure(action<iapplicationbuilder> next)
    {
      return builder =>
      {
        builder.usemiddleware<requestapiinsightbeginmiddleware>();
        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<noinsightattribute>();
      return noinsight != null;
    }
  }

程序地址: https://github.com/cheesebar/apiinsights

以上就是本文的全部内容，希望对大家的学习有所帮助，也希望大家多多支持。