前面有两篇铺垫博文,在博文《200303-如何优雅的在java中统计代码块耗时》,其最后提到了根据利用java agent来统计方法耗时
博文《200316-IDEA + maven零基础构建java agent项目中则详细描述了搭建一个java agent开发测试项目的全过程
本篇博文将进入java agent的实战,手把手教你如何是实现一个统计方法耗时的java agent
1. 基本姿势点
上面两节虽然手把手教你实现了一个hello world版agent,然而实际上对java agent依然是一脸茫然,所以我们得先补齐一下基础知识
首先来看agent的两个方法中的参数 Instrumentation
,我们先看一下它的接口定义
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26
|
void addTransformer(ClassFileTransformer transformer);
void retransformClasses(Class<?>... classes) throws UnmodifiableClassException;
long getObjectSize(Object objectToSize);
void appendToBootstrapClassLoaderSearch(JarFile jarfile);
Class[] getAllLoadedClasses();
|
前面两个方法比较重要,addTransformer方法配置之后,后续的类加载都会被Transformer拦截。对于已经加载过的类,可以执行retransformClasses来重新触发这个Transformer的拦截。类加载的字节码被修改后,除非再次被retransform,否则不会恢复。
通过上面的描述,可知
- 可以通过
Transformer
修改类
- 类加载时,会被触发Transformer拦截
2. 实现
我们需要统计方法耗时,所以想到的就是在方法的执行前,记录一个时间,执行完之后统计一下时间差,即为耗时
直接修改字节码有点麻烦,因此我们借助神器javaassist
来修改字节码
实现自定义的ClassFileTransformer
,代码如下
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31
| public class CostTransformer implements ClassFileTransformer { @Override public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined, ProtectionDomain protectionDomain, byte[] classfileBuffer) { if (!className.startsWith("com/git/hui/java/")) { return classfileBuffer; }
CtClass cl = null; try { ClassPool classPool = ClassPool.getDefault(); cl = classPool.makeClass(new ByteArrayInputStream(classfileBuffer));
for (CtMethod method : cl.getDeclaredMethods()) { method.addLocalVariable("start", CtClass.longType); method.insertBefore("start = System.currentTimeMillis();"); String methodName = method.getLongName(); method.insertAfter("System.out.println(\"" + methodName + " cost: \" + (System" + ".currentTimeMillis() - start));"); }
byte[] transformed = cl.toBytecode(); return transformed; } catch (Exception e) { e.printStackTrace(); } return classfileBuffer; } }
|
然后稍微改一下agent
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40
|
public class SimpleAgent {
public static void premain(String agentArgs, Instrumentation inst) { System.out.println("premain"); customLogic(inst); }
public static void agentmain(String agentArgs, Instrumentation inst) { System.out.println("agentmain"); customLogic(inst); }
private static void customLogic(Instrumentation inst) { inst.addTransformer(new CostTransformer(), true); } }
|
到此agent完毕,打包和上面的过程一样,接下来进入测试环节
创建一个DemoClz, 里面两个方法
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22
| public class DemoClz {
public int print(int i) { System.out.println("i: " + i); try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); } return i + 2; }
public int count(int i) { System.out.println("cnt: " + i); try { Thread.sleep(50); } catch (InterruptedException e) { e.printStackTrace(); } return i + 1; } }
|
然后对应的main方法如下
1 2 3 4 5 6 7 8 9 10 11 12 13
| public class BaseMain { public static void main(String[] args) throws InterruptedException { DemoClz demoClz = new DemoClz(); int cnt = 0; for (int i = 0; i < 20; i++) { if (++cnt % 2 == 0) { i = demoClz.print(i); } else { i = demoClz.count(i); } } } }
|
选择jvm参数指定agent方式运行(具体操作和上面一样),输出如下
虽然我们的应用程序中并没有方法的耗时统计,但是最终的输出却完美的打印了每个方法的调用耗时,实现了无侵入的耗时统计功能
到这里本文的java agent的扫盲 + 实战(开发一个方法耗时统计)都已经完成了,是否就宣告着可以小结了,并不是,下面介绍一下在实现上面的demo过程中遇到的一个问题
3. Exception in thread “main” java.lang.VerifyError: Expecting a stack map frame
在演示方法耗时的agent的示例中,并没有借助最开始的测试用例,而是新建了一个DemoClz
来做的,那么为什么这样选择呢,如果直接用第二节的测试用例会怎样呢?
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22
| public class BaseMain { public int print(int i) { System.out.println("i: " + i); try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); } return i + 2; }
public void run() { int i = 1; while (true) { i = print(i); } }
public static void main(String[] args) { BaseMain main = new BaseMain(); main.run(); }
|
依然通过jvm参数指定agent的方式,运行上面的代码,会发现抛异常,无法正常运行了
指出了在run方法这里,存在字节码的错误,我们统计耗时的Agent,主要就是在方法开始前和结束后各自新增了一行代码,我们直接补充在run方法中,则相当于下面的代码
上面的提示很明显的告诉了,最后一行语句永远不可能达到,编译就存在异常了;那么问题来了,作为一个java agent的提供者,我哪知道使用者有没有写这种死循环的方法,如果应用中有这么个死循环的任务存在,把我的agent一挂载上去,导致应用都起不来,这个锅算谁的????
下面提供解决方案,也很简单,在jvm参数中,添加一个-noverify
(请注意不同的jdk版本,参数可能不一样,我的本地是jdk8,用这个参数;如果是jdk7可以试一下-XX:-UseSplitVerifier
)
在IDEA开发环境下,如下配置即可
再次运行,正常了
4. 小结
本篇为实战项目,首先明确方法参数Instrumentation
它的接口定义,通过它来实现java 字节码的修改
我们通过实现自定义的ClassFileTransformer
,借助javassist来修改字节码,为每个方法的第一行和最后一行注入耗时统计的代码,从而实现方法耗时统计
最后留一个小问题,上面的实现中,当方法内部抛出异常时,我们注入的最后一行统计耗时会不会如期输出,如果不会,应该怎么修改,欢迎各位大佬留言指出解决方案
(具体解决方案可以在源码中获取哦,还有配套的测试case,求支持,求赞,求关注❀)
II. 其他
0. 相关
相关博文
相关源码
一灰灰的个人博客,记录所有学习和工作中的博文,欢迎大家前去逛逛
2. 声明
尽信书则不如,以上内容,纯属一家之言,因个人能力有限,难免有疏漏和错误之处,如发现bug或者有更好的建议,欢迎批评指正,不吝感激
3. 扫描关注
一灰灰blog