Logback 日志探针与动态化

2024-01-10 08:17:10

大家好，首先给大家做一个简短的自我介绍，我叫陶明凯，2014 年曾在百度糯米负责大数据推荐工程侧的研发工作，后来加入到创业公司，在创业公司经历了几次从无到有的工程架构的搭建，目前就职于神策，负责中台业务的工程架构工作。今天主要给大家分享的内容是神策在 log 日志探针与动态化的探索和实践，希望能够给大家带来一些不一样的收获。

一、前言

今天的分享主要分为如下几个方面：

第一个方面，首先会给大家去讲一下背景，就是在数据安全私有部署的场景下，在问题诊断这个层面上所面临的一些挑战。
第二个方面，就是方案，我们去做这种技术选型的背后的一些思路，包括一些方法。
第三个方面，就是实现，我们会把一些核心的一部分代码会让大家能够看到，包括它是如何去实现认知探针，包括动态实现是怎么去做到的。
第四个方面，就是总结，总结其实更多的是想告诉大家，不只是把技术和工具是如何使用的告诉大家，而是要去告诉大家在技术选型的背后的思路，它的方式是什么。

希望能通过本次的分享，从整个的技术本质，包括对于技术认知，在成长方面，让大家能够有所收获。

二、背景：数据安全 & 私有部署

第一点背景，就是数据安全和数据部署。其实这一块还有一个副标题：以数据安全为基点，私有部署场景下的问题诊断，它会面临哪些挑战呢？

首先我们先讲一下神策在这一方面的一些设计理念，如下图：

第一个理念就是数据安全，这是神策我们这边非常敬重的一个理念。它能够进行私有化部署，就是以数据安全为基点，支持私有化一键自动部署。

第二个理念就是全端采集，数据采集与建模就是客户端服务器、业务数据、线下数据等，能够进行全端数据的采集与建模。

第三个理念就是多维分析，让数据采集到之后，我们能够给客户进行实时的多维度的分析，这一点是非常重要的。

第四个理念就是深度开发，我们不只是要去提供一个产品的技术层面的解决方案，更多的是能够集成一些用户的深度开发方面的需求。

在基于这 4 点设计理念的情况下，其中的数据安全是我们最核心，也是最敬重的一方面。基于这四方面设计理念，神策会有一个整套完整的采集方案，如下图：

大家可以看到上面这个图片，从注册、浏览、下单、支付、收货这几个环节，然后通过 SDK 上传到数据仓库，然后进行一个整体的分析。其实分析从采集到分析这个链路是非常长的，当这个链路长的情况下，它会带来一个非常大的问题，只要有一个小点发生异常，发生问题，整个的排查，或者说一个请求的跟踪问题，都会面临一个非常大的挑战。这个挑战都有哪些呢？我们可以看一下，下面的图片：

第一个挑战就是保留现场。基于数据安全加私有化部署这一块，其实对于客户的操作行为，请求的入参出参是不可见的。所以说我们要想办法，要在问题发生的时候去保留完整的现场。

第二个就是快速定位，能否快速定位取决于我们的日志是否打印得非常全，包括异常，堆栈信息也是非常全，我们能够拿到请求的完整的一个链路日志，这也是我们快速定位的一个必要条件。

第三个就是动态输出，动态输出这一块其实大家可能会有这样一个痛点，就是当现场出现问题去排查日志的时候发现代码中没有记日志，是不是非常头疼？这个时候我要再去改代码，把日志加进去，然后再进行重启。此时我已经不满足第一点保留现场，已经把现场给破坏掉了。所以说这个时候要有一个动态输出的能力，动态输出的话就是指定改变现成的级别和指定输出参数。

我们把这三个挑战，汇总为一个核心的问题，就是更快速和更精准的定位异常问题，这就是我们面临挑战的核心。当我们把这个核心挑战的问题确认了，知道我们要解决的问题是什么，那么接下来就是我们对应的方案的技术选择了。我们开始第二节。

三、方案：Logback & Instrument

第二部分的话，它也有一个副标题：就是如何无侵入性的增强系统动态日志的能力，我们怎么能够无侵入，并且还能够增强系统的日志能力，并且还是动态的，这是非常重要的。大家可以先在这个地方可以有这样一个思考。技术方案选型前，我们先梳理一下，我们要达成的目标，如下图：

第一个目标的话，就是动态指定日志输出信息。

第二个目标的话，就是动态更改请求日志级别。

第三个目标的话，就是其它系统要去接，要去集成动态日志能力的时候，必须是无侵入性的，必须要对它们改造的成本非常低。

第四个目标的话，就是动态的要抓取请求的完整的一个验收日志。

至此，这个时候我们在这几个个目标上可以拎出几个关键词来：

第一个关键词就是动态增强
第二个关键词就是无侵入
第三个关键词就是链路日志

那么首先讲第一个动态增强，什么是动态增强？它到底增强的是什么呢？其实就是字节码增强，字节码增强是一种非常成熟的技术，它能够进行修改或者动态生成全新的字节码，我们可以把自己的代码增强了，那我们如何进行增强呢？又是遵循什么样的原则呢？我们可以遵循 Java 编译系统组织 class 文件的格式和结构，能够生成相应的二进制数据，然后再把这个二进制数据重新加载到我们的运行时环境当中。这个时候我们就动态增强了我们的代码，具体如下图：

然后我们再看一下上面这张图，其实在这里面会有两个核心点，第一个核心点，红色字体的部分就是可以根据 class 组织结构生成对应的字节码，这里和核心点我们把它称为字节码增强。第二个核心点就是上面红色的曲线就是加载，这个加载必须是要运行时动态的。如果说不能够达到运行时动态，其实我们只是做了字节码增强，而没有在运行时候能够把字节码进行实时的替换，那么字节码增强所使用的场景非常有限，这其实是非常重要的。接下来，我们先介绍字节码增强的技术选型。

第一个技术的话就是 ASM，它是一个字节码级别的一个字节码编程，大家有用到过的话，可以感觉到它是纯粹的操作字节码，要求研发人员对字节码必须要很熟悉，同时也能带来非常好的字节码性能。ASM 具体代码增强流程，如下图：

大家可以看上面这张图，ASM 它是通过 class reader 去读取字节码，然后通过 visitor 的一个访问者模式，大家如果有兴趣可以去看 asm 的源码的时候，你会发现访问者模式会有很多用到的地方，处理完字节码之后，然后再通过 class writer 去生成字节码，这样一个过程帮助我们就可以做到对字节码增强。

第二个技术的话就是 Javassist，大家会发现 ASM 是在字节层次上的编程，这种方式对编程是非常不友好的，有没有其它的框架能够对编程既简单又能够实现我们字节增强的，那就是 Javassist，同时它的性能可能会比 asm 会差一些，但是它的优点是可以直接使用 Java 编码的形式进行动态改变类的一个结构，或者说去动态的生成类。大家可以看下面这张图，它可以首先去构造一个 ClassPool 的对象，然后去获取目标类的一个 class，然后对 Class 类的一个对象进行生成并装载 class 的一个字节码。

再来讲第二个点，就是动态重载，上面我们只做了字节码增强，但是我们不能够把它在运行时动态重载，这个时候 Instrument 来完成这些事情。Instrument 是专门为 Java 语言编写的一个插装服务，它能够依赖 JVMTI 一个 Attach 机制，能够去动态的装载 class 文件。所以说在它可以达到在一个持续运行，并已经加载的所有类的 jvm 中，还能够利用字节码增强技术对其中的 Class 的行为做替换并重新加载，这一点是非常重要的。如果说没有这一点的话，其实你只有之前字节码是达不到我们想要的一个效果。

大家可以看下面这张图，这张图其实是一个 JPDA 的一个分层模型，然后最下面这一层是 JDI Debuger 接口。然后中间这一层是一个交互通道，JDWP，然后再往上真正的要去操作虚拟机层面的，JVMTI 提供了一些 API 它可以进行类的加载，甚至还可以去修改 class path。就在这一点上大家可以看到，Instrument 的这一点是非常强大的。

至此，我们字节码增强，动态重载，这部分已经给大家梳理完成。接下来，针对于日志框架这个层面，其实没有太多的技术上的一个可挑剔的地方。其实最常用的就是首先它的接口必须是要用 slf4j 的，它的优势是什么呢？因为我们的日志实现会有很多种，比如：logback、log4j、log4j2 等，面对这些不同日志实现，Slf4j 提供了接口层上层的统一，然后它下面通过中间绑定和桥接来去适配我们不同的日志的实现，所以说这一块的话我们重点是选用的 Slf4j 和 Logback，Logback 这一块我看中它的最重要一点的话，它的产品配置文件是支持条件处理的，条件处理就是它的配置文件里面可以去配一些 if else 和一些表达式的解析，这样的话它的定制化会是非常强的。还有一个它可以支持动态定义属性，就当我们的 jvm 参数传参过来的时候，我们可以对它这个参数可以对它进行一些特殊的解析。

还有一点，也是最重要的一点，它可以引入外部的配置文件，这样的话作为业务中台这一个层面的话，它就可以写一个通用的 Logback 的一个日志文件，同时可以去把外部一些自定义的 Logback 配置引入到日志文件当中，这是它一个支持的特性。然后其它的一个自定义支持就是 append，filter 和 layout 和 MDC 机制。MDC 机制也是非常重要的，这一点是每个日志框架必备的一个操作。

最终，我们在技术方案选型方面，选择了以下三种技术：

四、实现：日志探针 & 动态实现

接着下一部分，前面我们把这个技术方案确定之后，那又是如何实现的呢？也就是说 Instrument 和 JVMTI 它是如何赋能 Logback 实现动态能力的。我们接下来在之前我们再把目标过一遍。首先是我们 4 个目标，对吧？第一个动态指定日志输出信息。第二个是动态更改请求的日志级别，动态更改请求级别其实是非常重要的，接下来我们可以给大家演示一下。

第三个的话就是其它系统的无侵入性接入，这一点也非常重要，直接决定了日后的落地推动。第四个的话就是动态抓取请求列入日志，好吧，这就是我们 4 个目标。

然后我们看一下这 4 个目标是是如何通过上面的三个技术进行解决的。我们先第一个运行时动态，我们要做的是字节码增强，同时能够进行动态的承载。目标一就是动态指定日志输出信息，我们用到的技术就是动态增强。大家可以先看一下下面的这部分代码，如下图：

上面这张图的这部分代码是我们真正常的一个代码实现，然后我们对它进行自检的增强，做哪些增强？大家看下面这张图，transform 就是 Instrument 中 ClassFileTransform。如下图：

如上图，首先我们想在 test 的方法执行之前去插入一条日志，这就叫 At before。然后我们在 29 行就是 result to put result1 之前去加一个去往 result 变量里边再添加一个 kv 值，然后在 30 行的时候，我们再去输出 kv 的具体 result 里面 k，看它有没有添加进去，然后在最后我们再去方法执行完，最后就把具体的日志 dynamic and after 这个东西打出来。通过代码可以看到，其实我们就加了通过字节码增强的方式，加了以上四行代码。Ok，这个应该是比较好理解的。

OK，接下来我们需要在定义完了 class transform 之后，我们必须要进行一个 Agent 的定义，只有进行了 Agent 的定义，JVMTI 才可以动态的进行 Attach，如下图：

到目前为止，基本上就是我们把字节码增强和 Instrument 动态重载，和 Java Agent 这个层面代码就已经写完了。大家可以看这个代码基本上没有几行代码，这个时候我们就要把 Agent 进行打包，打包的话我们可以通过 Maven 的方式进行打包。简单的配置如下：

接着就是实现第三个目标，就其它系统叫无侵入性的去接入。这个时候我们利用到了 JVMTI 的一个 attach 的 API，我们看它是怎么去用的。具体代码如图：

如上图，这个时候我们仍然是利用了 VirtualMachine 实例，通过它可以去传入一个 JVM PID，然后再通过 loadAgent，将传入的 Jar Path Attach 到目标 JVM 中，这个时候这个目标 JVM 会动态的去加载一个类的时候，会进行类的一个 transform 的重新的 retransform 的 class，会把增强过的类的字节码增强，并进行一个动态的重载。

接下来，我们看一下字节码增强和动态重载的具体效果演示如何？

1. 首先，访问：

http://localhost:8080/test，其响应的数据会和代码中实现的一致。如下图：（1）

（2）

2. 接下来，访问：

http://localhost:8080/attach，进行动态 Attach Agent，进行字节码增强和动态重载。如下图：

（1）

（2）

3. 再次，访问：

http://localhost:8080/test，确认 Attach 是否已生效。如下图：

（1）

（2）

最后我们接着再往下看，关于 Logback，是如何动态更改当前请求的日志级别，而不影响其它线程的 Log。我们要解决的这一个目标就是会涉及到两个类，一个类就是 MDCLogFilter，MDC 大家可以用的就是一个线程本地的变量，这个时候我们通过 MDC 去把对应的参数里面的 level 这个级别放到当前线程中进去。如下图：

然后还有一个就是它可以根据里面存的值动态的去计算我们当前这条日志的对应的 level，对应的日志级别应该是什么？从而进行一个过滤。可以看到下面这张图，dynamic 随后的 filter 绿色框这一部分，就已经能够判断我当前的 MDC 的里面的 key 的 level，和我当前日志这条来往是否匹配，如果匹配的话，这个时候就会返回 on accept 允许是接受的。如下图：