日志收集系统在大搜车的探索和实践

引言

大搜车日志分为两种：业务日志和链路日志。

业务日志是业务开发人员在代码里面自己打印的日志，为方便开发人员快速查阅分布在多台机器上的日志，我们提供了业务日至平台，供开发自助接入。目前接入的系统400+，每天产生的日志量7亿+，高峰时期每秒要处理5W+的日志。

链路日志对应的则是链路追踪平台（trace），通过traceID把跨系统调用的所有下游系统串联起来，想要了解详细的话可以参考开源的pinpoint。 链路日志每天日志量30亿+，高峰每秒要处理8W+的日志。我们只保留七天的数据，大概45T。

开源社区有很多优秀的日志收集组件，如logkit,logstack,flume等。我们公司因为早前就在其它场景下使用过flume，运维同学也积累了丰富的运维经验，所以采集组件直接使用的flume。个人感觉而已，logkit和logstack更轻量，作为采集端更合适~

下面开始进入正题，介绍下我们的整体架构以及遇到的坑，还有就是根据自身的业务特点做的特殊优化~

整体架构图

详细说明

如上图所示，整体上分为四个模块：日志采集，日志处理，日志存储以及展示和应用，下面开始详细介绍每个模块。

日志采集

日志采集最大的难题就是业务日志在机器山存放的路径以及文件名称并不统一(运维最开始没有制定标准)，而且日志格式和滚动策略等都是业务开发人员自己配置的。所以接入我们的系统需要使用方自己录入日志存放目录以及通过 正则表达式 指定日志格式(如下图)。 配置好日志目录和格式，系统会把这些配置推送给flume(开源版本不支持该推送配置的功能，我们修改了开源版本使其支持)，日志采集就开始了。

第一步我就遇到了一个大坑，先说现象：有的应用莫名其妙的最新日志就收集不上来了，登录到机器上查看，发现采集进程还在，用top命令查看，发现日志采集进程占用cpu达到100%

cpu100%问题排查我就不详诉了,可以点超链接自行查看。通过线程堆栈，可以看到是正则表达式在搞鬼。这里需要引入正则表达式的执行原理：

传统的NFA引擎运行所谓的“贪婪的”匹配回溯算法（longest-leftmost），以指定顺序测试正则表达式的所有可能的扩展并接受第一个匹配项。传统的NFA回溯可以访问完全相同的状态多次，在最坏情况下，它的执行速度可能 非常慢，但它 支持子匹配。代表性有：GNU Emacs,Java,ergp,less,more,.NET语言, PCRE library,Perl,PHP,Python,Ruby,sed,vi等，一般高级语言都采用该模式。

在通过下面这个实例理解下：

源字符DEF,匹配正则表达式是：/D\w+F/ 匹配开始： 第一步，/D 正确匹配到D,而\w+会贪婪的匹配最长的字符串，也就是 EF。然后F因为匹配不到任何字符，导致匹配失败。 第二步，因为上面的匹配失败了，回溯算法往后退一位， /D 正确匹配到D,而\w+ 匹配到 E,F匹配到 F,匹配成功。

上面的例子因为源字符串比较短，正则表达式也不复杂，所以只回溯了一次。但是我们的真实场景一条业务日志长度几百设置上千，而用户写的正则可能不止 有\w+，还会有.+ 等等。所以这也就造成了上面的问题，最新日志收集不上来（解析日志耗费的时间太长了），而且CPU100%（因为一直在运算，并不是卡住）。

明确了问题直接上解决方案吧，不想铺垫了。。。

第一步就是要快速失败，如果解析一条日志超过100ms，就应该把它归类为解析失败，继续后面的日志处理。所以可以把日志解析丢到异步线程池中，主线程通过拿到的Future控制超时时间。

第二步就是如果超时了，要能够中断正在匹配的正则表达式。这个时候遇到的问题是正则表达式本身是不响应中断，不过好在天无绝人之路，观察发现正则表达式源字符串要求传入的类型是 CharSequence，而每次回溯时，都会调用charAt方法，所以可以通过创建一个新的类，实现 CharSequence，并且在charAt中判断是否被中断。这样的话，就可以让正则表达式的解析过程响应中断了~~，CharSequence 实现类代码如下

public class InterruptibleCharSequence implements CharSequence {

    CharSequence inner;

    public InterruptibleCharSequence(CharSequence inner) {
        super();
        this.inner = inner;
    }

    @Override
    public char charAt(int index) {
        if (Thread.currentThread().isInterrupted()) {
            throw new RuntimeException("Interrupted!");
        }
        return inner.charAt(index);
    }

    @Override
    public int length() {
        return inner.length();
    }

    @Override
    public CharSequence subSequence(int start, int end) {
        return new InterruptibleCharSequence(inner.subSequence(start, end));
    }

    @Override
    public String toString() {
        return inner.toString();
    }
}

日志处理

所有机器上的flume采集程序，收集到的日志会先上报给单独搭建的flume代理层集群，这是因为运维不希望太多的机器直连kaka。代理层没有做任何处理，直接把日志丢到kafka。

kafka的性能和稳定性是经过历史验证的，所以选它作为中间缓存层没什么争议。当然，其它的mq也更有优势，可以根据公司技术栈灵活选择。像号称下一代的mq:pulsar我们也打算调研试用下~

为什么不直接写后端的ES呢？这是因为需要缓冲层来削峰填谷，可能有点抽象，举个实际的例子，我们的业务高峰期，日志的产生速度高于ES的写入速度。业务系统那边基本都会配置了日志文件翻滚，这样就有可能造成还没来得及收上来的日志被冲掉了。

kafka后面挂的是flink集群，上面跑了四个job:

业务日志Job:负责存储业务日志

链路日志的Job：负责存储链路日志

监控报表的Job: 主要是统计一些指标，如qps，错误率等等，利用到了flink的窗口

报警中心的Job：业务日志可以根据用户自定义的报警规则报警，而链路日志则可以对框架层面的超时，错误报警，如dubbo调用超时~

日志存储

日志存储主要是把数据写入ES，单独来讲是因为不同的产品存储方式不同。这块也是整个系统最大的短板，为了优化写入做了很多工作。

业务日志存储

首先分析下业务日志的场景，大家基本上只查看自己应用的日志，痛点是可能分布在不同的机器上，经常使用的姿势是根据关键字全文匹配。而且以前使用kibana的时候，因为分词导致查询出来的结果不精确很不爽。

针对这个特点，我们设计的后端存储方式是：每个应用每天一个索引，同时创建索引的时候通过MappingTemplate禁用掉分词。

优缺点： 这是设计方式是面向单应用查询的，所以查询速度比较快，而且是全文匹配的暴力查询，用户体验比较好。但是也导致了ES集群中索引的数量过多，会多占用一些内存。

还有一个小坑，是关于限流功能的。我们想实现的功能是，针对打日志特别多的应用，比如说一天打几千万条的日志，超过阈值就自动限流该应用，后面的日志就不采集了。 统计应用每天的日志量，是放在flink集群做的，但是实际应用中发现，当flink统计到某个应用采集量已经达到上限，比如说1000W，想要限流已经为时已晚，因为这时候这个应用可能已经有5000W日志堆在kafka了。  也就是说，在flink集群统计有严重的滞后性，后来我们又在flume采集的时候增加了单机限流。

链路日志存储

链路日志的数据量特别庞大，同时因为经常需要跨系统查询，所以不能按照系统的维度建索引。不过相对于业务日志，因为都是框架层面打印的，所以格式是统一的。针对这种特点，按照每小时建一个索引，保证索引数据量不会太大。Mapping策略上，也是禁用分词，提前解析出（应用，路径，环境，线程）字段，让ES索引起来。这样用户在界面上根据这些字段过滤就会有比较好的性能表现。

其它的写入性能优化

在接入量快速增长的阶段，ES首先扛不住了，写入性能无法满足快速增长的日志量。虽然可能通过加机器缓解问题，但成本也要控制，所以优化ES写入性能迫在眉睫，下面列出的是实践过程中最有效的方式，其它的可以自行百度~

• 增大刷盘时间(refresh_interval):默认是1s，我们时间过程中调到了5s。调大之后写入性能上升还是比较明显的，带来的问题是日志写入5s之后才能被查询到，不过5s延迟延迟业务上是完全可以接受的。
• 0备份并且关掉事务日志（“durability”: “async”）：这个对写入性能的提高是大幅度的，几乎是两倍的提升，我们的集群最高可以写到15W+。但是问题是无法保证可靠性，万一挂了怎么办？  我们的解决方式是kafka保存12小时的数据+低峰期（晚上）备份。  首先kafka保存12小时的数据保证了即使flink挂了或者ES挂了，都可以通过重置消费位点把数据找回来。晚上备份的话，保证了十二小时之前的数据就不会丢了
• 提前创建索引：业务日志每到晚上零点的时候，都会堆积数据。这是因为这个时候在大量的创建索引，写入速度自然受影响。解决思路就是提前把索引创建好
• 第三方幂等：首先说明这个我还没尝试过，因为现在写入性能够了，就没怎么在折腾，思路写出来供大家参考。  我们为了防止ES数据重复写入，是通过指定id的方式实现了幂等。这个对ES性能消耗还是比较大的（大概15%）。并且index的数据规模越大，性能越低，因为它要判断这个id是否已经存在。  如果把这个幂等控制拿到外面去做，让ES直接存就好了，性能肯定有进一步提升

日志应用

日志展示

可以根据关键字或者过滤条件快速搜索日志，免去了登录多台机器的麻烦

日志报警

把查询条件设置为报警规则，如下图，10分钟类日志中出现Exception关键字，次数大于1次，将触发报警。技术实现是通过flink，扩展窗口机制，实现了动态窗口（有时间这块可以详细写下）。

数据大盘

基于trace日志形成的数据大盘，QPS、耗时百分位图等信息，详细可以看另一片文章。