Java ASM使用logback日志级别动态切换的方法

魁首哥

作者

Java ASM使用logback日志级别动态切换的方法

这篇文章主要讲解了“JavaASM使用logback日志级别动态切换的方法”，文中的讲解内容简单清晰，易于学习与理解，下面请大家跟着小编的思路慢慢深入，一起来研究和学习“JavaASM使用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的配置文件中，增加定时扫描器即可，如：

<configurationscan="true"scanPeriod="30seconds"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/><bootclasspath>${java.home}/lib/rt.jar</bootclasspath></compilerArguments></configuration></plugin></plugins></build>

三、编写attrach启动类

packageagent;importjava.lang.instrument.Instrumentation;importjava.lang.instrument.UnmodifiableClassException;/***@authordengbp*@ClassNameLogbackAgentMain*@Descriptionattach启动器*@date3/25/226:27PM*/publicclassLogbackAgentMain{privatestaticStringFILTER_CLASS="ch.qos.logback.classic.Logger";publicstaticvoidagentmain(StringagentArgs,Instrumentationinst)throwsUnmodifiableClassException{System.out.println("agentArgs:"+agentArgs);inst.addTransformer(newLogBackFileTransformer(agentArgs),true);Class[]classes=inst.getAllLoadedClasses();for(inti=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;}}}}

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

packageagent;importjdk.internal.org.objectweb.asm.ClassReader;importjdk.internal.org.objectweb.asm.ClassVisitor;importjdk.internal.org.objectweb.asm.ClassWriter;importjava.lang.instrument.ClassFileTransformer;importjava.security.ProtectionDomain;/***@authordengbp*@ClassNameLogBackFileTransformer*@Description字节码文件转换器*@date3/25/226:25PM*/publicclassLogBackFileTransformerimplementsClassFileTransformer{privatefinalStringlevel;privatestaticStringCLASS_NAME="ch/qos/logback/classic/Logger";publicLogBackFileTransformer(Stringlevel){this.level=level;}@Overridepublicbyte[]transform(ClassLoaderloader,StringclassName,Class<?>classBeingRedefined,ProtectionDomainprotectionDomain,byte[]classfileBuffer){if(!CLASS_NAME.equals(className)){returnclassfileBuffer;}ClassReadercr=newClassReader(classfileBuffer);ClassWritercw=newClassWriter(cr,ClassWriter.COMPUTE_FRAMES);ClassVisitorcv1=newLogBackClassVisitor(cw,level);/*ClassVisitorcv2=newLogBackClassVisitor(cv1);*///asm框架使用到访问模式和责任链模式//ClassReader只需要accept责任链中的头节点处的ClassVisitor即可cr.accept(cv1,ClassReader.SKIP_FRAMES|ClassReader.SKIP_DEBUG);System.out.println("end...");returncw.toByteArray();}}

五、实现Logger元素的访问者

packageagent;importjdk.internal.org.objectweb.asm.ClassVisitor;importjdk.internal.org.objectweb.asm.MethodVisitor;importorg.objectweb.asm.Opcodes;/***@authordengbp*@ClassNameLogBackClassVisitor*@DescriptionLogger类元素访问者*@date3/25/225:01PM*/publicclassLogBackClassVisitorextendsClassVisitor{privatefinalStringlevel;/***asm版本*/privatestaticfinalintASM_VERSION=Opcodes.ASM4;publicLogBackClassVisitor(ClassVisitorclassVisitor,Stringlevel){super(ASM_VERSION,classVisitor);this.level=level;}@OverridepublicMethodVisitorvisitMethod(intaccess,Stringname,Stringdescriptor,Stringsignature,String[]exceptions){MethodVisitormv=super.visitMethod(access,name,descriptor,signature,exceptions);returnnewLogFilterMethodVisitor(api,mv,access,name,descriptor,level);}}

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

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

packageagent;importjdk.internal.org.objectweb.asm.Label;importjdk.internal.org.objectweb.asm.MethodVisitor;importjdk.internal.org.objectweb.asm.commons.AdviceAdapter;importorg.objectweb.asm.Opcodes;/***@authordengbp*@ClassNameLogFilterMethodVisitor*@DescriptionLogger类日志过滤方法元素访问者*@date3/25/225:01PM*/publicclassLogFilterMethodVisitorextendsAdviceAdapter{privateStringmethodName;privatefinalStringlevel;privatestaticfinalStringfilterAndLog_1="filterAndLog_1";privatestaticfinalStringfilterAndLog_2="filterAndLog_2";privatestaticfinalStringfilterAndLog_0_Or3Plus="filterAndLog_0_Or3Plus";protectedLogFilterMethodVisitor(intapi,MethodVisitormethodVisitor,intaccess,Stringname,Stringdescriptor,Stringlevel){super(api,methodVisitor,access,name,descriptor);this.methodName=name;this.level=level;}/***Description在访问方法的头部时被访问*@param*@returnvoid*@Authordengbp*@Date3:36PM4/1/22**/@OverridepublicvoidvisitCode(){System.out.println("visitCodemethod");super.visitCode();}@OverrideprotectedvoidonMethodEnter(){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*@returnvoid*@Authordengbp*@Date2:20PM3/31/22**/privatevoidmodifyLogLevel_1(){Labell0=newLabel();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");Labell1=newLabel();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);Labell2=newLabel();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;");Labell3=newLabel();mv.visitJumpInsn(Opcodes.IF_ACMPNE,l3);Labell4=newLabel();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");Labell5=newLabel();mv.visitJumpInsn(Opcodes.IF_ICMPLE,l5);Labell6=newLabel();mv.visitLabel(l6);mv.visitLineNumber(396,l6);mv.visitInsn(Opcodes.RETURN);mv.visitLabel(l3);mv.visitLineNumber(398,l3);mv.visitFrame(Opcodes.F_APPEND,1,newObject[]{"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);Labell7=newLabel();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);Labell8=newLabel();mv.visitLabel(l8);mv.visitLineNumber(403,l8);mv.visitInsn(Opcodes.RETURN);Labell9=newLabel();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的加载类

importcom.sun.tools.attach.VirtualMachine;importjava.io.IOException;importjava.io.UnsupportedEncodingException;/***@authordengbp*@ClassNameMyAttachMain*@Descriptionjar执行命令：*@date3/25/224:12PM*/publicclassMyAttachMain{privatestaticfinalintARGS_SIZE=2;publicstaticvoidmain(String[]args){if(args==null||args.length!=ARGS_SIZE){System.out.println("请输入进程id和日志级别(ALL、TRACE、DEBUG、INFO、WARN、ERROR、OFF),如：31722info");return;}VirtualMachinevm=null;try{System.out.println("修改的进程id:"+args[0]);vm=VirtualMachine.attach(args[0]);System.out.println("调整日志级别为："+args[1]);vm.loadAgent(getJar(),args[1]);}catch(Exceptione){e.printStackTrace();}finally{if(vm!=null){try{vm.detach();}catch(IOExceptione){e.printStackTrace();}}}}privatestaticStringgetJar()throwsUnsupportedEncodingException{StringjarFilePath=MyAttachMain.class.getProtectionDomain().getCodeSource().getLocation().getFile();jarFilePath=java.net.URLDecoder.decode(jarFilePath,"UTF-8");intbeginIndex=0;intendIndex=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("jarpath:"+jarFilePath);returnjarFilePath;}}

八、打包执行

寻找目标程序

执行jar

java-Xbootclasspath/a:/Library/Java/JavaVirtualMachines/jdk1.8.0_191.jdk/Contents/Home/lib/tools.jar-cpchange-log-agent-1.0.1.jarMyAttachMain52433DEBUG

java-Xbootclasspath/a:/Library/Java/JavaVirtualMachines/jdk1.8.0_191.jdk/Contents/Home/lib/tools.jar-cpchange-log-agent-1.0.1.jarMyAttachMain52433ERROR

java-Xbootclasspath/a:/Library/Java/JavaVirtualMachines/jdk1.8.0_191.jdk/Contents/Home/lib/tools.jar-cpchange-log-agent-1.0.1.jarMyAttachMain52433INFO