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

V2AS问路

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

阅读原文时间：2022年04月01日阅读：1

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

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

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

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

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

方案一：logback自动扫描更新

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

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

它的缺点是：

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

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

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

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

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

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

一、idea创建maven工程

二、maven引入依赖

org.ow2.asm asm 7.1 asm-commons org.ow2.asm 7.1 com.sun tools 1.8 system /Library/Java/JavaVirtualMachines/jdk1.8.0_191.jdk/Contents/Home/lib/tools.jar

org.apache.maven.plugins maven-jar-plugin 3.2.0 agent.LogbackAgentMain true true maven-compiler-plugin 1.8 1.8 UTF-8 ${java.home}/lib/rt.jar

三、编写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();  
}&nbsp;

七、最后再编写加载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****

手机扫一扫

移动阅读更方便

你可能感兴趣的文章