拓展 NLog 优雅的输送日志到 Logstash

Posted 2020-11-11 行走即歌

在上上篇博客通过对aspnetcore启动前配置做了一些更改，以及对nlog进行了自定义字段，可以把请求记录输送到mysql，正式情况可能不会这么部署。因为近期也在学习elk，所以就打算做一个实例，结合nlog把日志输送到logstash，当然现在有开源的.netcore性能监控系统，但是本文的重点是nlog的拓展以及如何拓展。

现有的工作方式

在nlog中，我们在配置文件targets节点下添加一个target就可以定义一个日志输出目标，当我们需要把日志输送到logstash时，需要添加一个target节点，其type为Network，填上address，layout等等，一般有如下配置

<targets>
  <target xsi:type="Network"
        name="logstash_apiinsight"
        keepConnection="false"
        layout="${customer-ip} ${customer-method} ${customer-path} ${customer-bytes} ${customer-duration}"
        address ="tcp://192.168.93.135:8102"
  >
  </target>
</targets>
<rules>
  <logger name="WebApp.*" minlevel="Trace" writeTo="logstash_apiinsight" />
</rules>

我们可以在layout中定义很多个字段，然后在当logstash接受到数据包时通过grok来依次解析每一个字段，如果对正则比较熟悉这种方式确实能够工作，但是当日志记录的字段数越来越多时，其实是很麻烦的。我个人比较喜欢json，日志通过json发送时，数据更加语义化，在logstash的处理也会容易很多，组织成json发送有什么缺点吗？现在能想到的只有它会多发送属性的名称从而浪费一些资源！因为如果按上面配置的layout，日志的传输过程中是不会发送 message,date,level 这些属性的名称的，在logstash做稍作处理就可以解析这些字段。要注意的是，上面的 layout中声明的字段是不存在的，为了方便测试我们可以直接填数据

layout="127.0.0.1 GET /home/index 2000 50"

此时只要你在WebApp命名空间下记录日志，输送到logstash的始终都是这一行内容

如果您是通过rpm来安装的logstash，那么在 /etc/logstash/conf.d 下新建一个 test.conf 输入下面的内容，同时打开服务器的 8012端口

input {
  tcp {
    port => 8102
  }
}
filter {
  grok {
    match => { "message" => "%{IP:client} %{WORD:method} %{URIPATHPARAM:request} %{NUMBER:bytes} %{NUMBER:duration}" }
  }
}
output {
  elasticsearch {
    hosts => "localhost:9200"
    index => "sample"
   }
}

启动.netcore程序，多记几次日志，观察kibana就会有如下输出

这里虽然是假数据但是想要真的也很简单，在我的上上一片博客中就多次使用了NLog中LayoutRenderer这个父类来自定义字段

[LayoutRenderer("customer-ip")]
public class ProtocolApiInsightRenderer : LayoutRenderer
{
    protected override void Append(StringBuilder builder, LogEventInfo logEvent)
    {
        builder.Append("127.0.0.1");
    }
}

 现有方式有一些问题是很难解决的。如果日志本身有空格呢？我们该寻找哪个字符作为分隔符？再比如当部分字段可空部分字段不可空的时候，当要传三个数字到logstash，结果只传了两个，那grok该怎么解析呢，虽然不一定会遇到这种情况，但也反映了语义化的json是更容易处理的。

拓展NLog

思考的过程

其实到这里我们不难发当我们需要向服务器发送tcp数据包时现现有的工作方式是存在不足的，准确来说是向logstash发送数据包是存在不足的，因为这里本身就是一个 NLog.Targets.NetworkTarget，它的原本目标就是向TCP发送日志，在使用nlog的过程中我们知道在向数据库服务器发送日志的时候可以通过配置文件中的parameter节点表明字段，但是NetworkTarget是不支持这样的方式的

<target name = "db_log" xsi:type="Database"
  dbProvider="MySql.Data.MySqlClient.MySqlConnection, MySql.Data"
  connectionString="${var:connectionString}"
  >
  <commandText>
        insert into log(
        application, logged, level, message,
        logger, callsite, exception, ip, user, servername, url
        ) values(
        @application, @logged, @level, @message,
        @logger, @callsite, @exception, @ip, @user, @servername, @url
        );
  </commandText>
  <parameter name = "@application" layout="${apiinsight-application}" />
  <parameter name = "@logged" layout="${date}" />
  <parameter name = "@level" layout="${level}" />
  <parameter name = "@message" layout="${message}" />
  <parameter name = "@logger" layout="${logger}" />
  <parameter name = "@callSite" layout="${callsite:filename=true}" />
  <parameter name = "@exception" layout="${apiinsight-request-exception}" />
  <parameter name = "@IP" layout="${aspnet-Request-IP}"/>
  <parameter name = "@User" layout="${apiinsight-request-user}"/>
  <parameter name = "@serverName" layout="${apiinsight-request-servername}" />
  <parameter name = "@url" layout="${apiinsight-request-url}" />
</target>

通过观察源码还可以发现这里所有的type都是通过继承Target这个抽象类来定义的，所以现在很容易想到一种方式来拓展，那就是写一个 LogstashTarget 继承Target，但是你会发现这要要做的东西非常多，并且可能需要进一步的阅读NLog的源码，NLog代码量相对其他框架来说以及很少了，但是至少还要做这些工作

1、添加类似parameter的节点

2、TCP连接池和消息发送队列

虽然这两项都可以借鉴 NetworkTarget 和 DatabaseTarget 他们的工作方式，但是很明显这样的代码（在你不修改源码的情况下）你会写两遍，软件设计的基本原则就是尽量拓展少修改。

所以我们很快会想到第二种方法，既然要结合NetworkTarget 和 DatabaseTarget他们两的特点，那我是否可以写一个LogstashTarget继承自NetworkTarget，就避免了了 TCP 连接池和消息发送队列的重复代码，柑橘哪不对！因为还要重复DatabaseTarget的一部分代码！这里是我的思考过程，其实最主要的原因还是想少些一些代码吧，所以我考虑到了第三种方法

拓展不行，将就用着

类型LayoutRenderer从出现到现在我一直都是认为它就是用来自定义字段的，但是观察源码就会发现它的子类非常多，并没有去研究每一个子类都做了什么，但是现在他可以最快的帮助我实现想要的功能。这里我定义了一个抽象类

/// <summary>
///     由于 <see cref="NLog.Targets.NetworkTarget"/> 没有提供 parameter 字段
///     为了更好的把数据组织到 logstash，我们可以在这里自定义字段最终以 json 传输到 logstash
/// </summary>
public abstract class LogstashLayoutRenderer : LayoutRenderer
{
    protected HttpContext httpContext => HttpContextProvider.Current;
    protected async override void Append(StringBuilder builder, LogEventInfo logEvent)
    {
        builder.Append(await ProviderJson());
    }
    protected abstract Task<string> ProviderJson();
}

抽象类LogstashLayoutRenderer通过子类实现的方法ProviderJson向builder写入数据，这种方法最简单是因为我的根本需求是想给Logstash发一个json格式的日志，所以这样也比较好理解，至于接下来我想发这个格式的json还是那个格式的json都可以通过实现该类型来达到我的目标，所以现在的方法依然使用NetworkTarget作为输出目标。 此外这里把 HttpContext放进来似乎有点奇怪，可能当时懒得写那么长HttpContextProvider.Current这样去拿吧，可以在这里看它的代码是怎么实现的 https://www.cnblogs.com/cheesebar/p/9078207.html 。不过这样的做法还有一个缺点就是不能在配置文件中定义想要的字段

Logstash的字段

/// <summary>
///     给 <see cref="NetworkTarget"/> 优雅的自定义字段
/// </summary>
public abstract class LayoutFieldBase
{
    public abstract Task<string> ProviderField();
    public abstract string ProviderFieldName { get; }
    public HttpContext httpContext => HttpContextProvider.Current;
}

在给这个类取名字的时候是LogstashFieldBase好呢还是NetworkFieldBase好呢。纠结中就叫LayoutFieldBase吧，其实他是有两个作用的，一方面LogstashLayoutRenderer的ProviderJson方法会搜集所有的字段组织成json，这些字段都是继承自该接口的，另一方面如果我不仅要把这个相同的日志记录到Logstash可能还要记录到db或者文件。LogstashLayoutRenderer的实现者总是包含很多个LayoutFieldBase，这个是写死的，同时因为可能还要记录到db，那我还为每一个LayoutFieldBase的实现者定义了一个LayoutRendererBase。可以看到Append方法调用子类的实现方法来填写响应的字段值，也就是说子类提供一个LayoutFieldBase就可以避免同样的代码写两遍

/// <summary>
///     已知的是这里通过 <see cref="LayoutFieldBase"/> 给 <see cref="NetworkTarget"/> 优雅的自定义字段
///     但是考虑到有些字段可能同事也要输入到 <see cref="DatabaseTarget"/>，但是相同字段的值获取方式是一样的
///     Append 方法通过代理接口 <see cref="ILayoutProxy"/> 提供的 <see cref="LayoutFieldBase"/> 取值
/// </summary>
public abstract class LayoutRendererBase : LayoutRenderer, ILayoutProxy
{
    public abstract Type LayoutType { get; }

    private LayoutFieldBase _layout;

    public LayoutFieldBase Layout
    {
        get
        {
            if (_layout == null)
            {
                if (HttpContextProvider.Current != null)
                {
                    _layout = HttpContextProvider.Current.RequestServices.GetServices<LayoutFieldBase>().First(t => t.GetType() == LayoutType);
                }
            }
            return _layout;
        }
    }

    protected async override void Append(StringBuilder builder, LogEventInfo logEvent)
    {
        builder.Append(await Layout?.ProviderField());
    }
}

当输出目标非Network的时候，依然可以通LayoutRendererBase的实现者的LayoutRenderer特性在配置文件中应用它，这里看一个例子

[LayoutRenderer("apiinsight-application")]
public class ApplicationApiInsightRenderer : LayoutRendererBase
{
    public override Type LayoutType => typeof(AppLayout);
}

预先定义了一些LayoutFieldBase和LayoutRendererBase

真正进行字段值计算的是左边的这些类型，右边的这些类型通过代理使用左边的类型来提供字段，所有的LayoutFieldBase都在开始时注入到容器

/// <summary>
///     应用程序名称
/// </summary>
public class AppLayout : LayoutFieldBase
{
    public override string ProviderFieldName => "app";
    public async override Task<string> ProviderField()
    {
        if (httpContext != null)
        {
            var env = httpContext.RequestServices?.GetService<IHostingEnvironment>();
            return env.ApplicationName;
        }
        return string.Empty;
    }
}
[LayoutRenderer("apiinsight-application")]
public class ApplicationApiInsightRenderer : LayoutRendererBase
{
    public override Type LayoutType => typeof(AppLayout);
}

/// <summary>
///     配合 NLog （Target Network） 注入自定义字段
///     自定义字段都继承自 <see cref="LayoutFieldBase"/>
/// </summary>
public static class LogstashLayoutBaseServiceCollectionExtensions
{
    public static void AddLayoutBase(this IServiceCollection services)
    {
        var layouts = AppDomain.CurrentDomain.GetAssemblies().SelectMany(t => t.GetTypes())
            .Where(t => typeof(LayoutFieldBase).IsAssignableFrom(t) && !t.IsAbstract);

        foreach (var item in layouts)
        {
            services.AddSingleton(typeof(LayoutFieldBase), item);
        }
    }
}

 拓展完成

对于拓展这件事，其实已经做完了，因为接下来的事情是业务相关的，在回想一下通过自定义的LogstashLayoutRenderer组织Json到Logstash。在拓展中已经定义了一些可能用到的字段比如说应用程序名称AppLayout，请求方法MethodLayout等等

asp.netcore接口请求统计

新增的start和time字段

回顾之前我写的博客发现只有请求开始时间和请求消耗时间没有在之前的拓展写进来，所在在这里加进来

/// <summary>
///     请求到达的时间
/// </summary>
public class StartLayout : LayoutFieldBase
{
    public override string ProviderFieldName => "start";

    public async override Task<string> ProviderField()
    {
        if (httpContext != null)
        {
            var _apiInsightsKeys = httpContext.RequestServices.GetService<IApiInsightsKeys>();

            if (httpContext != null)
            {
                if (httpContext.Items.TryGetValue(_apiInsightsKeys.StartTimeName, out var start) == true)
                {
                    return ((DateTime)start).ToString("yyyy/MM/dd hh:mm:ss");
                }
            }
        }
        return string.Empty;
    }
}
/// <summary>
///     请求消耗的时间
/// </summary>
public class TimeLayout : LayoutFieldBase
{
    public override string ProviderFieldName => "interval";

    public async override Task<string> ProviderField()
    {
        if (httpContext != null)
        {
            var _apiInsightsKeys = httpContext.RequestServices.GetService<IApiInsightsKeys>();

            if (httpContext != null)
            {
                if (httpContext.Items.TryGetValue(_apiInsightsKeys.StopWatchName, out var stopWatch) == true)
                {
                    return (stopWatch as Stopwatch).ElapsedMilliseconds.ToString();
                }
            }
        }
        return string.Empty;
    }
}

 测试的时候可能我也要看统计有没有成功记录，需要对比数据库和elk，所以数据库依然要写，这里定义相应的LayoutRenderer

[LayoutRenderer("apiinsight-start")]
public class StartApiInsightRenderer : LayoutRendererBase
{
    public override Type LayoutType => typeof(StartLayout);
}
[LayoutRenderer("apiinsight-time")]
public class TimeApiInsightRenderer : LayoutRendererBase
{
    public override Type LayoutType => typeof(TimeLayout);
}

 核心ApiInsightLogstashLayoutRenderer

在调试的时候发现所有的LayoutRenderer都是单例的，所以这边的Layouts其实都只会创建一次，所以性能会比想象的好很多，json就是通过newtonsoft这个裤来创建的。

/// <summary>
///     在 NLog 配置文件中，Network 我们只需要注册一个 Layout，名称就是 logstash-apiinsight
/// </summary>
[LayoutRenderer("logstash-apiinsight")]
public class ApiInsightLogstashLayoutRenderer : LogstashLayoutRenderer
{
    static readonly Type[] LayoutTypes = new[] {
        typeof(StartLayout),
        typeof(TimeLayout),
        typeof(ProtocolLayout),
        typeof(HostLayout),
        typeof(PortLayout),
        typeof(PathLayout),
        typeof(QueryLayout),
        typeof(ClientIPLayout),
        typeof(ServerIPLayout),
        typeof(AuthLayout),
        typeof(HttpStatusLayout),
        typeof(AppLayout),
        typeof(MethodLayout),
    };

    static LayoutFieldBase[] Layouts;

    void Init(IServiceProvider serviceProvider)
    {
        var services = serviceProvider.GetServices<LayoutFieldBase>();

        Layouts = services.Where(t => LayoutTypes.Contains(t.GetType())).ToArray();

        if (Layouts.Length != LayoutTypes.Length)
        {
            throw new Exception(nameof(ApiInsightLogstashLayoutRenderer) + " 的 Layouts 和预定义数目的不匹配");
        }
    }

    protected async override Task<string> ProviderJson()
    {
        if (Layouts == null)
        {
            Init(httpContext.RequestServices);
        }
        var dic = new Dictionary<string, string>();

        foreach (var item in Layouts)
        {
            dic.Add(item.ProviderFieldName, await item.ProviderField());
        }

        var json = JObjectHelper.CreateSimpleJson(dic).Replace(Environment.NewLine, string.Empty);

        return json;
    }
}

 logstash配置

input {
  tcp {
    port => 8102
  }
}

filter{
  json {
    source => "message"
  }

  date {
    match => [ "start", "yyyy/MM/dd HH:mm:ss" ]
  }

  mutate{
    convert => {
      "statusCode" => "integer"
      "interval" => "integer"
      "port" => "integer"
    }
  }

}

output {
  elasticsearch {
    hosts => "localhost:9200"
    index => "core-%{+YYYY.MM.dd}"
   }
}

这里就做了一些字段的类型转换，因为默认的所有字段都是string类型，是不方便统计的。

 nlog配置

<target xsi:type="Network"
      name="logstash_apiinsight"
      keepConnection="false"
      layout="${logstash-apiinsight}"
      address ="tcp://192.168.93.135:8103"
        >
</target>

 小结

因为近两天公司事情也比较少，事情做完了就乱捣鼓，在使用nlog的Network向Logstash发送数据的时候发现确实不大好用，所以就思考了这样的一个实现方式，基本的是可以了，但是还有一些功能比如说层级json怎么定义，这其实就是单纯的写代码，很有意思的一件事，如果您也有想法或者觉得我的代码有不好的地方或者可以改进的地方，欢迎一起讨论。

 程序地址：https://github.com/cheesebar/ApiInsights