logback日志级别动态切换的终极方案(asm使用)

博客 动态
0 120
羽尘
羽尘 2022-04-01 16:57:26
悬赏:0 积分 收藏

logback日志级别动态切换的终极方案(asm使用)

背景

一切皆有因果,所有事情,都有事件驱动。本方案的日志级别切换是由这样的背景下产生的:

  • 单个生产环境上,有几百近千个微服务
  • 日志级别切换不重启服务,要求即时生效果
  • 由业务开发人员去修改代码或增加相关依赖配置等涉及面广,推动进度慢
  • 后期动态实时过滤垃圾日志,减少io和磁盘空间成本

logback简介

在跟敌人发起战争之前,只有先发解敌方的情况,才能做到百战百胜。要想对logback的日志级别做动态切换,首先至少对logback做个初步的了解、和看看它有没有提供现成的实现方案。下面简单介绍一下logback跟这次需求有关的内容。

logback是java的日志开源组件,是log4j创始人写的,目前主要分为3个模块

  1. logback-core:核心代码模块
  2. logback-classic:log4j的一个改良版本,同时实现了slf4j的接口
  3. logback-access:访问模块与Servlet容器集成提供通过Http来访问日志的功能
  4. ContextInitializer类是logback自动配置流程的逻辑实现
  5. 日志级别由Logger维护和使用。其成员变量Level正是由Logger维护
  6. Logger中有filterAndLog_0_Or3Plus、filterAndLog_1、filterAndLog_2三个不同参数的过滤日志输出方法
  7. Logger中的setLevel就是对日志级别的维护

解决方案

在满头苦干之前,先了解市面上的方案。是设计师们乃至产品大佬们寻求最优解决方案的思路。

方案一:logback自动扫描更新

这个方案是logback自带现成的实现,只要开启配置就可以实现所谓的日志级别动态切换。配置方法:在logback的配置文件中,增加定时扫描器即可,如:

<configuration scan="true" scanPeriod="30 seconds" debug="false">

该方案可以不需要研发成本,运维人员自己配上并能使用。

它的缺点是:

  • 每次调整扫描间隔时间都要重启服务
  • 90%以上的扫描都是无用功,因为生产上的日志级别不可能经常有切换需求,也不允许这么做
  • 生效不实时,如果设定在一分钟或几分钟扫描一次,那么让日志级别调整后生效就不是即时生效的,不过这个可以忽略
  • 该方案满足不了我们的垃圾日志丢弃的需求,比如根据某些关键字丢弃日志的输出。针对这种历史原因打印很多垃圾日志的情况,考虑到时间成本,不可能让业务研发去优化。

方案二:ASM动态修改字节码

当然,还有其它方案,如:自己定义接口api。来直接调用Logger中的setLevel方法,达到调整级别的目的;springboot的集成。

这些方案都不避免不了专主于业务开发角色的参与。

通过asm动态修改指令,该方案除了能满足调整日志级别即时生效之外。还可以满足过滤日志的需求

具体实现如下,在这里就不对asm做介绍了,不了解的同学,需要先去熟悉asm、java agent和jvm的指令:

一、idea创建maven工程

二、maven引入依赖

<dependencies>        <dependency>            <groupId>org.ow2.asm</groupId>            <artifactId>asm</artifactId>            <version>7.1</version>        </dependency>        <dependency>            <artifactId>asm-commons</artifactId>            <groupId>org.ow2.asm</groupId>            <version>7.1</version>        </dependency>        <dependency>            <groupId>com.sun</groupId>            <artifactId>tools</artifactId>            <version>1.8</version>            <scope>system</scope>            <systemPath>/Library/Java/JavaVirtualMachines/jdk1.8.0_191.jdk/Contents/Home/lib/tools.jar</systemPath>        </dependency>    </dependencies><build>  <plugins>      <plugin>          <groupId>org.apache.maven.plugins</groupId>          <artifactId>maven-jar-plugin</artifactId>          <version>3.2.0</version>          <configuration>              <archive>                  <manifestEntries>                      <!-- 主程序启动类 -->                      <Agent-Class>                          agent.LogbackAgentMain                      </Agent-Class>                      <!-- 允许重新定义类 -->                      <Can-Redefine-Classes>true</Can-Redefine-Classes>                      <!-- 允许转换并重新加载类 -->                      <Can-Retransform-Classes>true</Can-Retransform-Classes>                  </manifestEntries>              </archive>          </configuration>      </plugin>      <plugin>          <artifactId>maven-compiler-plugin</artifactId>          <configuration>              <source>1.8</source>              <target>1.8</target>              <encoding>UTF-8</encoding>              <compilerArguments>                  <verbose />                  <!-- 将jdk的依赖jar打入项目中-->                  <bootclasspath>${java.home}/lib/rt.jar</bootclasspath>              </compilerArguments>          </configuration>      </plugin>  </plugins></build>

三、编写attrach启动类

package agent;import java.lang.instrument.Instrumentation;import java.lang.instrument.UnmodifiableClassException;/** * @author dengbp * @ClassName LogbackAgentMain * @Description attach 启动器 * @date 3/25/22 6:27 PM */public class LogbackAgentMain {    private static String FILTER_CLASS = "ch.qos.logback.classic.Logger";    public static void agentmain(String agentArgs, Instrumentation inst) throws UnmodifiableClassException {        System.out.println("agentArgs:" + agentArgs);        inst.addTransformer(new LogBackFileTransformer(agentArgs), true);        Class[] classes = inst.getAllLoadedClasses();        for (int i = 0; i < classes.length; i++) {            if (FILTER_CLASS.equals(classes[i].getName())) {                System.out.println("----重新加载Logger开始----");                inst.retransformClasses(classes[i]);                System.out.println("----重新加载Logger完毕----");                break;            }        }    }}

四、实现字节码转换处理器

package agent;import jdk.internal.org.objectweb.asm.ClassReader;import jdk.internal.org.objectweb.asm.ClassVisitor;import jdk.internal.org.objectweb.asm.ClassWriter;import java.lang.instrument.ClassFileTransformer;import java.security.ProtectionDomain;/** * @author dengbp * @ClassName LogBackFileTransformer * @Description 字节码文件转换器 * @date 3/25/22 6:25 PM */public class LogBackFileTransformer implements ClassFileTransformer {    private final String level;    private static String CLASS_NAME = "ch/qos/logback/classic/Logger";    public LogBackFileTransformer(String level) {        this.level = level;    }    @Override    public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined, ProtectionDomain protectionDomain, byte[] classfileBuffer) {        if (!CLASS_NAME.equals(className)) {            return classfileBuffer;        }        ClassReader cr = new ClassReader(classfileBuffer);        ClassWriter cw = new ClassWriter(cr, ClassWriter.COMPUTE_FRAMES);        ClassVisitor cv1 = new LogBackClassVisitor(cw, level);        /*ClassVisitor cv2 = new LogBackClassVisitor(cv1);*/        // asm框架使用到访问模式和责任链模式        // ClassReader 只需要 accept 责任链中的头节点处的 ClassVisitor即可        cr.accept(cv1, ClassReader.SKIP_FRAMES | ClassReader.SKIP_DEBUG);        System.out.println("end...");        return cw.toByteArray();    }}

五、实现Logger元素的访问者

package agent;import jdk.internal.org.objectweb.asm.ClassVisitor;import jdk.internal.org.objectweb.asm.MethodVisitor;import org.objectweb.asm.Opcodes;/** * @author dengbp * @ClassName LogBackClassVisitor * @Description Logger类元素访问者 * @date 3/25/22 5:01 PM */public class LogBackClassVisitor extends ClassVisitor {    private final String level;    /**     * asm版本     */    private static final int ASM_VERSION = Opcodes.ASM4;    public LogBackClassVisitor(ClassVisitor classVisitor, String level) {        super(ASM_VERSION, classVisitor);        this.level = level;    }    @Override    public MethodVisitor visitMethod(int access, String name, String descriptor, String signature,                                     String[] exceptions) {        MethodVisitor mv = super.visitMethod(access, name, descriptor, signature, exceptions);        return new LogFilterMethodVisitor(api, mv, access, name, descriptor, level);    }}

六、最后实现Logger关键方法的访问者

该访问者(类),实现日志级别的切换,需要对Logger的三个日志过滤方法进行指令的修改。原理是把命令行入参的日志级别参数值覆盖其成员变量effectiveLevelInt的值,由于篇幅过大,只贴核心部分代码,请看下面:

package agent;import jdk.internal.org.objectweb.asm.Label;import jdk.internal.org.objectweb.asm.MethodVisitor;import jdk.internal.org.objectweb.asm.commons.AdviceAdapter;import org.objectweb.asm.Opcodes;/** * @author dengbp * @ClassName LogFilterMethodVisitor * @Description Logger类日志过滤方法元素访问者 * @date 3/25/22 5:01 PM */public class LogFilterMethodVisitor extends AdviceAdapter {    private String methodName;    private final String level;    private static final String filterAndLog_1 = "filterAndLog_1";    private static final String filterAndLog_2 = "filterAndLog_2";    private static final String filterAndLog_0_Or3Plus = "filterAndLog_0_Or3Plus";    protected LogFilterMethodVisitor(int api, MethodVisitor methodVisitor, int access, String name, String descriptor, String level) {        super(api, methodVisitor, access, name, descriptor);        this.methodName = name;        this.level = level;    }    /**     * Description 在访问方法的头部时被访问     * @param     * @return void     * @Author dengbp     * @Date 3:36 PM 4/1/22     **/    @Override    public void visitCode() {        System.out.println("visitCode method");        super.visitCode();    }    @Override    protected void onMethodEnter() {        System.out.println("开始重写日志级别为:"+level);        System.out.println("----准备修改方法----");        if (filterAndLog_1.equals(methodName)) {            modifyLogLevel_1();        }        if (filterAndLog_2.equals(methodName)) {            modifyLogLevel_2();        }        if (filterAndLog_0_Or3Plus.equals(methodName)) {            modifyLogLevel_3();        }        System.out.println("重写日志级别成功....");    }

其中modifyLogLevel_1(); modifyLogLevel_2();modifyLogLevel_3();分别对应filterAndLog_1、filterAndLog_2、filterAndLog_0_Or3Plus方法指令的修改。下面只贴modifyLogLevel_1的实现

 /**     * Description 修改目标方法:filterAndLog_1     * @param     * @return void     * @Author dengbp     * @Date 2:20 PM 3/31/22     **/    private void modifyLogLevel_1(){        Label l0 = new Label();        mv.visitLabel(l0);        mv.visitLineNumber(390, l0);        mv.visitVarInsn(Opcodes.ALOAD, 0);        mv.visitLdcInsn(level);        mv.visitMethodInsn(Opcodes.INVOKESTATIC, "ch/qos/logback/classic/Level", "toLevel", "(Ljava/lang/String;)Lch/qos/logback/classic/Level;", false);        mv.visitFieldInsn(Opcodes.GETFIELD, "ch/qos/logback/classic/Level", "levelInt", "I");        mv.visitFieldInsn(Opcodes.PUTFIELD, "ch/qos/logback/classic/Logger", "effectiveLevelInt", "I");        Label l1 = new Label();        mv.visitLabel(l1);        mv.visitLineNumber(392, l1);        mv.visitVarInsn(Opcodes.ALOAD, 0);        mv.visitFieldInsn(Opcodes.GETFIELD, "ch/qos/logback/classic/Logger", "loggerContext", "Lch/qos/logback/classic/LoggerContext;");        mv.visitVarInsn(Opcodes.ALOAD, 2);        mv.visitVarInsn(Opcodes.ALOAD, 0);        mv.visitVarInsn(Opcodes.ALOAD, 3);        mv.visitVarInsn(Opcodes.ALOAD, 4);        mv.visitVarInsn(Opcodes.ALOAD, 5);        mv.visitVarInsn(Opcodes.ALOAD, 6);        mv.visitMethodInsn(Opcodes.INVOKEVIRTUAL, "ch/qos/logback/classic/LoggerContext", "getTurboFilterChainDecision_1", "(Lorg/slf4j/Marker;Lch/qos/logback/classic/Logger;Lch/qos/logback/classic/Level;Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Throwable;)Lch/qos/logback/core/spi/FilterReply;", false);        mv.visitVarInsn(Opcodes.ASTORE, 7);        Label l2 = new Label();        mv.visitLabel(l2);        mv.visitLineNumber(394, l2);        mv.visitVarInsn(Opcodes.ALOAD, 7);        mv.visitFieldInsn(Opcodes.GETSTATIC, "ch/qos/logback/core/spi/FilterReply", "NEUTRAL", "Lch/qos/logback/core/spi/FilterReply;");        Label l3 = new Label();        mv.visitJumpInsn(Opcodes.IF_ACMPNE, l3);        Label l4 = new Label();        mv.visitLabel(l4);        mv.visitLineNumber(395, l4);        mv.visitVarInsn(Opcodes.ALOAD, 0);        mv.visitFieldInsn(Opcodes.GETFIELD, "ch/qos/logback/classic/Logger", "effectiveLevelInt", "I");        mv.visitVarInsn(Opcodes.ALOAD, 3);        mv.visitFieldInsn(Opcodes.GETFIELD, "ch/qos/logback/classic/Level", "levelInt", "I");        Label l5 = new Label();        mv.visitJumpInsn(Opcodes.IF_ICMPLE, l5);        Label l6 = new Label();        mv.visitLabel(l6);        mv.visitLineNumber(396, l6);        mv.visitInsn(Opcodes.RETURN);        mv.visitLabel(l3);        mv.visitLineNumber(398, l3);        mv.visitFrame(Opcodes.F_APPEND, 1, new Object[]{"ch/qos/logback/core/spi/FilterReply"}, 0, null);        mv.visitVarInsn(Opcodes.ALOAD, 7);        mv.visitFieldInsn(Opcodes.GETSTATIC, "ch/qos/logback/core/spi/FilterReply", "DENY", "Lch/qos/logback/core/spi/FilterReply;");        mv.visitJumpInsn(Opcodes.IF_ACMPNE, l5);        Label l7 = new Label();        mv.visitLabel(l7);        mv.visitLineNumber(399, l7);        mv.visitInsn(Opcodes.RETURN);        mv.visitLabel(l5);        mv.visitLineNumber(402, l5);        mv.visitFrame(Opcodes.F_SAME, 0, null, 0, null);        mv.visitVarInsn(Opcodes.ALOAD, 0);        mv.visitVarInsn(Opcodes.ALOAD, 1);        mv.visitVarInsn(Opcodes.ALOAD, 2);        mv.visitVarInsn(Opcodes.ALOAD, 3);        mv.visitVarInsn(Opcodes.ALOAD, 4);        mv.visitInsn(Opcodes.ICONST_1);        mv.visitTypeInsn(Opcodes.ANEWARRAY, "java/lang/Object");        mv.visitInsn(Opcodes.DUP);        mv.visitInsn(Opcodes.ICONST_0);        mv.visitVarInsn(Opcodes.ALOAD, 5);        mv.visitInsn(Opcodes.AASTORE);        mv.visitVarInsn(Opcodes.ALOAD, 6);        mv.visitMethodInsn(Opcodes.INVOKESPECIAL, "ch/qos/logback/classic/Logger", "buildLoggingEventAndAppend", "(Ljava/lang/String;Lorg/slf4j/Marker;Lch/qos/logback/classic/Level;Ljava/lang/String;[Ljava/lang/Object;Ljava/lang/Throwable;)V", false);        Label l8 = new Label();        mv.visitLabel(l8);        mv.visitLineNumber(403, l8);        mv.visitInsn(Opcodes.RETURN);        Label l9 = new Label();        mv.visitLabel(l9);        mv.visitLocalVariable("this", "Lch/qos/logback/classic/Logger;", null, l0, l9, 0);        mv.visitLocalVariable("localFQCN", "Ljava/lang/String;", null, l0, l9, 1);        mv.visitLocalVariable("marker", "Lorg/slf4j/Marker;", null, l0, l9, 2);        mv.visitLocalVariable("level", "Lch/qos/logback/classic/Level;", null, l0, l9, 3);        mv.visitLocalVariable("msg", "Ljava/lang/String;", null, l0, l9, 4);        mv.visitLocalVariable("param", "Ljava/lang/Object;", null, l0, l9, 5);        mv.visitLocalVariable("t", "Ljava/lang/Throwable;", null, l0, l9, 6);        mv.visitLocalVariable("decision", "Lch/qos/logback/core/spi/FilterReply;", null, l2, l9, 7);        mv.visitMaxs(9, 8);        mv.visitEnd();    } 

七、最后再编写加载attach Agent的启动类

import com.sun.tools.attach.VirtualMachine;import java.io.IOException;import java.io.UnsupportedEncodingException;/** * @author dengbp * @ClassName MyAttachMain * @Description jar 执行命令: * @date 3/25/22 4:12 PM */public class MyAttachMain {    private static final int ARGS_SIZE = 2;    public static void main(String[] args) {        if (args == null || args.length != ARGS_SIZE) {            System.out.println("请输入进程id和日志级别(ALL、TRACE、DEBUG、INFO、WARN、ERROR、OFF),如:31722 info");            return;        }        VirtualMachine vm = null;        try {            System.out.println("修改的进程id:" + args[0]);            vm = VirtualMachine.attach(args[0]);            System.out.println("调整日志级别为:" + args[1]);            vm.loadAgent(getJar(), args[1]);        } catch (Exception e) {            e.printStackTrace();        } finally {            if (vm != null) {                try {                    vm.detach();                } catch (IOException e) {                    e.printStackTrace();                }            }        }    }    private static String getJar() throws UnsupportedEncodingException {        String jarFilePath = MyAttachMain.class.getProtectionDomain().getCodeSource().getLocation().getFile();        jarFilePath = java.net.URLDecoder.decode(jarFilePath, "UTF-8");        int beginIndex = 0;        int endIndex = jarFilePath.length();        if (jarFilePath.contains(".jar")) {            endIndex = jarFilePath.indexOf(".jar") + 4;        }        if (jarFilePath.startsWith("file:")) {            beginIndex = jarFilePath.indexOf("file:") + 5;        }        jarFilePath = jarFilePath.substring(beginIndex, endIndex);        System.out.println("jar path:" + jarFilePath);        return jarFilePath;    }}

八、打包执行

  • 寻找目标程序

  • 执行jar
java  -Xbootclasspath/a:/Library/Java/JavaVirtualMachines/jdk1.8.0_191.jdk/Contents/Home/lib/tools.jar  -cp change-log-agent-1.0.1.jar MyAttachMain 52433  DEBUG
java  -Xbootclasspath/a:/Library/Java/JavaVirtualMachines/jdk1.8.0_191.jdk/Contents/Home/lib/tools.jar  -cp change-log-agent-1.0.1.jar MyAttachMain 52433 ERROR
java  -Xbootclasspath/a:/Library/Java/JavaVirtualMachines/jdk1.8.0_191.jdk/Contents/Home/lib/tools.jar  -cp change-log-agent-1.0.1.jar MyAttachMain 52433 INFO
  • 效果

 PS:如果出现校验失败(caused by: java.lang.verifyerror),请配上jvm参数:-noverify

延伸扩展

通过attach探针动态修改指令技术,可以在服务不停的情况下,实现部分代码的热部署; 也可以对代码的增强处理。下一期:代码热部署工具

【版权声明】

本文版权归作者(深圳伊人网网络有限公司)和博客园共有,欢迎转载,但未经作者同意必须在文章页面给出原文链接,否则保留追究法律责任的权利。如您有任何商业合作或者授权方面的协商,请给我留言:siqing0822@163.com

 

posted @ 2022-04-01 16:42 非洲羚羊 阅读(8) 评论(1) 编辑 收藏 举报
回帖
    羽尘

    羽尘 (王者 段位)

    2335 积分 (2)粉丝 (11)源码

     

    温馨提示

    亦奇源码

    最新会员