Java?ASM使用logback日志級(jí)別動(dòng)態(tài)切換方案展示

更新時(shí)間：2022年04月01日 18:04:37 作者：非洲羚羊

這篇文章主要介紹了Java?ASM使用logback日志級(jí)別動(dòng)態(tài)切換方案展示，有需要的朋友可以借鑒參考下，希望能夠有所幫助，祝大家多多進(jìn)步早日升職加薪

背景

一切皆有因果，所有事情，都有事件驅(qū)動(dòng)。本方案的日志級(jí)別切換是由這樣的背景下產(chǎn)生的：

單個(gè)生產(chǎn)環(huán)境上，有幾百近千個(gè)微服務(wù)
日志級(jí)別切換不重啟服務(wù)，要求即時(shí)生效果
由業(yè)務(wù)開(kāi)發(fā)人員去修改代碼或增加相關(guān)依賴(lài)配置等涉及面廣，推動(dòng)進(jìn)度慢
后期動(dòng)態(tài)實(shí)時(shí)過(guò)濾垃圾日志，減少io和磁盤(pán)空間成本

logback簡(jiǎn)介

在跟敵人發(fā)起戰(zhàn)爭(zhēng)之前，只有先發(fā)解敵方的情況，才能做到百戰(zhàn)百勝。要想對(duì)logback的日志級(jí)別做動(dòng)態(tài)切換，首先至少對(duì)logback做個(gè)初步的了解、和看看它有沒(méi)有提供現(xiàn)成的實(shí)現(xiàn)方案。下面簡(jiǎn)單介紹一下logback跟這次需求有關(guān)的內(nèi)容。

logback是java的日志開(kāi)源組件，是log4j創(chuàng)始人寫(xiě)的，目前主要分為3個(gè)模塊

logback-core:核心代碼模塊
logback-classic:log4j的一個(gè)改良版本，同時(shí)實(shí)現(xiàn)了slf4j的接口
logback-access:訪問(wèn)模塊與Servlet容器集成提供通過(guò)Http來(lái)訪問(wèn)日志的功能
ContextInitializer類(lèi)是logback自動(dòng)配置流程的邏輯實(shí)現(xiàn)
日志級(jí)別由Logger維護(hù)和使用。其成員變量Level正是由Logger維護(hù)
Logger中有filterAndLog_0_Or3Plus、filterAndLog_1、filterAndLog_2三個(gè)不同參數(shù)的過(guò)濾日志輸出方法
Logger中的setLevel就是對(duì)日志級(jí)別的維護(hù)

解決方案

在滿頭苦干之前，先了解市面上的方案。是設(shè)計(jì)師們乃至產(chǎn)品大佬們尋求最優(yōu)解決方案的思路。

方案一：logback自動(dòng)掃描更新

這個(gè)方案是logback自帶現(xiàn)成的實(shí)現(xiàn)，只要開(kāi)啟配置就可以實(shí)現(xiàn)所謂的日志級(jí)別動(dòng)態(tài)切換。配置方法：在logback的配置文件中，增加定時(shí)掃描器即可，如：

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

該方案可以不需要研發(fā)成本，運(yùn)維人員自己配上并能使用。

它的缺點(diǎn)是：

每次調(diào)整掃描間隔時(shí)間都要重啟服務(wù)
90%以上的掃描都是無(wú)用功，因?yàn)樯a(chǎn)上的日志級(jí)別不可能經(jīng)常有切換需求，也不允許這么做
生效不實(shí)時(shí)，如果設(shè)定在一分鐘或幾分鐘掃描一次，那么讓日志級(jí)別調(diào)整后生效就不是即時(shí)生效的，不過(guò)這個(gè)可以忽略
該方案滿足不了我們的垃圾日志丟棄的需求，比如根據(jù)某些關(guān)鍵字丟棄日志的輸出。針對(duì)這種歷史原因打印很多垃圾日志的情況，考慮到時(shí)間成本，不可能讓業(yè)務(wù)研發(fā)去優(yōu)化。

方案二：ASM動(dòng)態(tài)修改字節(jié)碼

當(dāng)然，還有其它方案，如：自己定義接口api。來(lái)直接調(diào)用Logger中的setLevel方法，達(dá)到調(diào)整級(jí)別的目的；springboot的集成。

這些方案都不避免不了專(zhuān)主于業(yè)務(wù)開(kāi)發(fā)角色的參與。

通過(guò)asm動(dòng)態(tài)修改指令，該方案除了能滿足調(diào)整日志級(jí)別即時(shí)生效之外。還可以滿足過(guò)濾日志的需求

具體實(shí)現(xiàn)如下，在這里就不對(duì)asm做介紹了，不了解的同學(xué)，需要先去熟悉asm、java agent和jvm的指令：

一、idea創(chuàng)建maven工程

二、maven引入依賴(lài)

<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>
                      <!-- 主程序啟動(dòng)類(lèi) -->
                      <Agent-Class>
                          agent.LogbackAgentMain
                      </Agent-Class>
                      <!-- 允許重新定義類(lèi) -->
                      <Can-Redefine-Classes>true</Can-Redefine-Classes>
                      <!-- 允許轉(zhuǎn)換并重新加載類(lèi) -->
                      <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的依賴(lài)jar打入項(xiàng)目中-->
                  <bootclasspath>${java.home}/lib/rt.jar</bootclasspath>
              </compilerArguments>
          </configuration>
      </plugin>
  </plugins>
</build>

三、編寫(xiě)attrach啟動(dòng)類(lèi)

package agent;
import java.lang.instrument.Instrumentation;
import java.lang.instrument.UnmodifiableClassException;
/**
 * @author dengbp
 * @ClassName LogbackAgentMain
 * @Description attach 啟動(dòng)器
 * @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開(kāi)始----");
                inst.retransformClasses(classes[i]);
                System.out.println("----重新加載Logger完畢----");
                break;
            }
        }
    }
}

四、實(shí)現(xiàn)字節(jié)碼轉(zhuǎn)換處理器

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 字節(jié)碼文件轉(zhuǎn)換器
 * @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框架使用到訪問(wèn)模式和責(zé)任鏈模式
        // ClassReader 只需要 accept 責(zé)任鏈中的頭節(jié)點(diǎn)處的 ClassVisitor即可
        cr.accept(cv1, ClassReader.SKIP_FRAMES | ClassReader.SKIP_DEBUG);
        System.out.println("end...");
        return cw.toByteArray();
    }
}

五、實(shí)現(xiàn)Logger元素的訪問(wèn)者

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類(lèi)元素訪問(wèn)者
 * @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);
    }
}

六、最后實(shí)現(xiàn)Logger關(guān)鍵方法的訪問(wèn)者

該訪問(wèn)者(類(lèi))，實(shí)現(xiàn)日志級(jí)別的切換，需要對(duì)Logger的三個(gè)日志過(guò)濾方法進(jìn)行指令的修改。原理是把命令行入?yún)⒌娜罩炯?jí)別參數(shù)值覆蓋其成員變量effectiveLevelInt的值，由于篇幅過(guò)大，只貼核心部分代碼，請(qǐng)看下面：

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類(lèi)日志過(guò)濾方法元素訪問(wèn)者
 * @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 在訪問(wèn)方法的頭部時(shí)被訪問(wèn)
     * @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("開(kāi)始重寫(xiě)日志級(jí)別為："+level);
        System.out.println("----準(zhǔn)備修改方法----");
        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("重寫(xiě)日志級(jí)別成功....");
    }

其中modifyLogLevel_1(); modifyLogLevel_2();modifyLogLevel_3();分別對(duì)應(yīng)filterAndLog_1、filterAndLog_2、filterAndLog_0_Or3Plus方法指令的修改。下面只貼modifyLogLevel_1的實(shí)現(xiàn)

/**
     * Description 修改目標(biāo)方法：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();
    }

七、最后再編寫(xiě)加載attach Agent的加載類(lèi)

import com.sun.tools.attach.VirtualMachine;
import java.io.IOException;
import java.io.UnsupportedEncodingException;

/**
 * @author dengbp
 * @ClassName MyAttachMain
 * @Description jar 執(zhí)行命令：
 * @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("請(qǐng)輸入進(jìn)程id和日志級(jí)別(ALL、TRACE、DEBUG、INFO、WARN、ERROR、OFF),如：31722 info");
            return;
        }
        VirtualMachine vm = null;
        try {
            System.out.println("修改的進(jìn)程id:" + args[0]);
            vm = VirtualMachine.attach(args[0]);
            System.out.println("調(diào)整日志級(jí)別為：" + 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;
    }
}

八、打包執(zhí)行

尋找目標(biāo)程序

執(zhí)行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