背景
一切皆有因果，所有事情，都有事件驅動。本方案的日誌級別切換是由這樣的背景下產生的：
- 單個生產環境上，有幾百近千個微服務
- 日誌級別切換不重啟服務，要求即時生效果
- 由業務開發人員去修改程式碼或增加相關依賴配置等涉及面廣，推動進度慢
- 後期動態實時過濾垃圾日誌，減少io和磁碟空間成本
logback簡介
在跟敵人發起戰爭之前，只有先發解敵方的情況，才能做到百戰百勝。要想對logback的日誌級別做動態切換，首先至少對logback做個初步的瞭解、和看看它有沒有提供現成的實現方案。下面簡單介紹一下logback跟這次需求有關的內容。
logback是java的日誌開源元件，是log4j創始人寫的，目前主要分為3個模組
- logback-core:核心程式碼模組
- logback-classic:log4j的一個改良版本，同時實現了
slf4j的介面 - logback-access:訪問模組與Servlet容器整合提供通過Http來訪問日誌的功能
- ContextInitializer類是logback自動配置流程的邏輯實現
- 日誌級別由Logger維護和使用。其成員變數Level正是由Logger維護
- Logger中有filterAndLog_0_Or3Plus、filterAndLog_1、filterAndLog_2三個不同引數的過濾日誌輸出方法
- 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