Java|Java ASM使用logback日志级别动态切换方案展示 JavaASM使用logback日志级别动态切

背景
logback简介
解决方案

方案一：logback自动扫描更新
方案二：ASM动态修改字节码

延伸扩展

【Java|Java ASM使用logback日志级别动态切换方案展示】
背景一切皆有因果，所有事情，都有事件驱动。本方案的日志级别切换是由这样的背景下产生的：

单个生产环境上，有几百近千个微服务
日志级别切换不重启服务，要求即时生效果
由业务开发人员去修改代码或增加相关依赖配置等涉及面广，推动进度慢
后期动态实时过滤垃圾日志，减少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的配置文件中，增加定时扫描器即可，如：

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

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

方案二：ASM动态修改字节码
当然，还有其它方案，如：自己定义接口api。来直接调用Logger中的setLevel方法，达到调整级别的目的；springboot的集成。
这些方案都不避免不了专主于业务开发角色的参与。
通过asm动态修改指令，该方案除了能满足调整日志级别即时生效之外。还可以满足过滤日志的需求
具体实现如下，在这里就不对asm做介绍了，不了解的同学，需要先去熟悉asm、java agent和jvm的指令：
一、idea创建maven工程

文章图片

二、maven引入依赖

org.ow2.asmasm7.1asm-commonsorg.ow2.asm7.1com.suntools1.8system/Library/Java/JavaVirtualMachines/jdk1.8.0_191.jdk/Contents/Home/lib/tools.jarorg.apache.maven.pluginsmaven-jar-plugin3.2.0agent.LogbackAgentMaintruetruemaven-compiler-plugin1.81.8UTF-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; }@Overridepublic 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; }@Overridepublic 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**/@Overridepublic void visitCode() {System.out.println("visitCode method"); super.visitCode(); }@Overrideprotected 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 52433DEBUG

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探针动态修改指令技术，可以在服务不停的情况下，实现部分代码的热部署；也可以对代码的增强处理。
以上就是Java ASM使用logback日志级别动态切换方案展示的详细内容，更多关于Java ASM动态切换logback日志级别的资料请关注脚本之家其它相关文章！