从一段计时代码开始

下面这段代码估计是我们见过（或写过）最多的代码了：

    long start = System.currentTimeMillis();
    /**
     * 代码逻辑
     */
    long end = System.currentTimeMillis();
    System.out.println("执行operate()方法使用了" + (end - start) + " mills");

要统计某些逻辑块的执行时间，这段代码可以说是非常简单且有效。不过如果要统计的方法很多时，为那些方法都填上这段代码就有些让人头疼了。主要有这样几个问题：

太多的重复工作；
计时内容散乱不好整理；
在业务代码中插入了业务无关的内容。

前两个缺点忍一忍多费些力气也不是不能克服。关键是最后一个问题，一旦意识到以后，再这样写就总是觉得怪怪的。

这些问题该怎么解决呢。最初的思路是用模板方法模式或装饰器模式来解决，不过很快就否定了这个思路：代码中的业务逻辑通常是各种各样的，只为了解决计时这样一个边缘需求就强行引入一些方法模式很容易造成代码结构的混乱，而且这样做也可以说是一种更深的代码侵入。发现此路不通后很自然就转到AOP方案上了——AOP生来就是为了解决这种问题的。

具体该怎么使用AOP呢。之前在使用Spring框架的时候曾经写过一个基于spring-aspect完成的方法计时的程序：

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.springframework.stereotype.Component;

import com.zhyea.robin.dev.annotation.StopWatch;
 
@Aspect
@Component
public class StopWatchContract {
 
	@Around("execution(* com.zhyea..*.*(..)) && @annotation(sw)")
	public void handle(final ProceedingJoinPoint pjd, StopWatch sw) throws Throwable {
		long start = System.currentTimeMills();
		try {
			pjd.proceed();
		} finally {
			long end = System.currentTimeMills();
			System.out.println("execute method " + sw.name() + " used " + (end-start) + " mills");
		}
	}
}

代码中的StopWatch是一个自定义注解。这段代码会计算所有在包com.zhyea下的以StopWatch注解标记的方法的执行时间。

但是工作中很多应用是不依赖Spring的，这时就应该考虑一下AOP的实现了。简单来说，AOP的实现就是在某些方法执行前后运行特定的代码（类似于装饰器模式）。这些代码可以直接插入到类中，也可以在方法执行前后引用。至于插入AOP代码的时机，大体上有如下几个：

类编译时；
类加载前；
调用方法时。

对应三种插入代码的时机有着不同的AOP的实现方案。在类编译时插入AOP代码的如AspectJ，在使用时需要特别定制的编译器；调用方法时实现AOP，就如同前面的SpringAspect的例子，需要框架的支持，否则还是有一些代码的侵入；至于在类加载时实现AOP，Spring也有提供方案，是依赖cglib实现，不过这里不展开了。

对于我们要解决的方法计时的问题，我们可以考虑采用在类加载时插入计时代码来实现。这里我们会用到java.lang.instrument包和asm。

java.lang.instrument 是 Java SE 5 的新特性。使用 Instrumentation，开发者可以构建一个独立于应用程序的代理程序（Agent），用来监测和协助运行在 JVM 上的程序，甚至能够替换和修改某些类的定义。

asm是一个 Java 字节码操控框架。它能被用来动态生成类或者增强既有类的功能。asm可以直接产生二进制 class 文件，也可以在类被加载入 Java 虚拟机之前动态改变类行为。

下面我们就用asm和instrument来实现下计时统计的需求。如下是一个测试类：

public class TestModel {

    public void operation() {
        System.out.println("operation...");
    }

}

在类中的operation方法中插入计时代码后：

public class TestModel {

    public void operation() {
        long start = System.currentTimeMillis();
        System.out.println("operation...");
        long end = System.currentTimeMillis();
        TimerClerk.add(TestModel.class.getName() + ".operation", (end - start));
    }
}

我们的目标就是将测试类转换成这段代码的样子。代码中的TimerClerk是一个计时统计工具类，可以忽略。

首先，我们先使用asm来完成插入计时代码的功能：

import com.zhyea.jspy.commons.tools.TimerClerk;
import org.objectweb.asm.ClassVisitor;
import org.objectweb.asm.MethodVisitor;
import org.objectweb.asm.Type;
import org.objectweb.asm.commons.AdviceAdapter;

import static org.objectweb.asm.Opcodes.ACC_INTERFACE;
import static org.objectweb.asm.Opcodes.ASM6;

public class TimerClassAdapter extends ClassVisitor {

    private boolean isInterface;
    private String owner;

    public TimerClassAdapter(ClassVisitor classVisitor) {
        super(ASM6, classVisitor);
    }

    @Override
    public void visit(int version,
                      int access,
                      String name,
                      String signature,
                      String superName,
                      String[] interfaces) {
        cv.visit(version, access, name, signature, superName, interfaces);
        isInterface = (access & ACC_INTERFACE) != 0;
        owner = name;
    }


    @Override
    public MethodVisitor visitMethod(int access,
                                     String name,
                                     String desc,
                                     String signature,
                                     String[] exceptions) {
        MethodVisitor mv = cv.visitMethod(access, name, desc, signature, exceptions);
        if (!isInterface && mv != null) {
            mv = new TimerMethodAdapter(mv, access, name, desc, owner, isInterface);
        }
        return mv;
    }


    public static class TimerMethodAdapter extends AdviceAdapter {

        private String owner;

        private boolean isInterface;

        private int start;

        private int end;

        private boolean isSkip = false;

        private static final String systemOwner =
                System.class.getName().replaceAll("\\.", "/");

        private static final String watcherOwner =
                TimerClerk.class.getName().replaceAll("\\.", "/");

        public TimerMethodAdapter(final MethodVisitor methodVisitor,
                                  final int access,
                                  final String name,
                                  final String desc,
                                  final String owner,
                                  final boolean isInterface) {
            super(ASM6, methodVisitor, access, name, desc);
            this.owner = owner + "." + name;
            this.isInterface = isInterface;
            this.isSkip = name.equals("<init>");
        }


        @Override
        protected void onMethodEnter() {
            if (!isSkip) {
                mv.visitMethodInsn(INVOKESTATIC, systemOwner, "currentTimeMillis", "()J", isInterface);
                start = newLocal(Type.LONG_TYPE);
                mv.visitVarInsn(LSTORE, start);
            }
        }


        @Override
        protected void onMethodExit(int opcode) {
            if (!isSkip) {
                mv.visitMethodInsn(INVOKESTATIC, systemOwner, "currentTimeMillis", "()J", isInterface);
                end = newLocal(Type.LONG_TYPE);
                mv.visitVarInsn(LSTORE, end);

                mv.visitLdcInsn(owner);

                mv.visitVarInsn(LLOAD, end);
                mv.visitVarInsn(LLOAD, start);
                mv.visitInsn(LSUB);

                mv.visitMethodInsn(INVOKESTATIC, watcherOwner, "add", "(Ljava/lang/String;J)V", isInterface);
            }
        }


        @Override
        public void visitMaxs(int maxStack, int maxLocals) {
            super.visitMaxs(maxStack + 4, maxLocals);
        }
    }
}

在代码中使用了AdviceAdapter这个类。通过这个类可以很方便地在进入方法和退出方法时插入代码。现在我们可以使用TimerClassAdapter在任意其他类中插入计时代码了。有心的话可以写一个main方法来试一下，也可以用反编译工具来查看生成的类看看是否和预期一致。

关于asm的更多内容有需要请参考官方文档。（在csdn也有一份中文文档可以参考，点击此处下载）。

然后是在instrument中使用上面定义的TimerClassAdapter类：

import com.zhyea.jspy.agent.asm.TimerClassAdapter;
import org.objectweb.asm.ClassReader;
import org.objectweb.asm.ClassWriter;

import java.lang.instrument.ClassFileTransformer;
import java.lang.instrument.IllegalClassFormatException;
import java.lang.instrument.Instrumentation;
import java.security.ProtectionDomain;

public class CustomTransformer implements ClassFileTransformer {

    private String option;
    
    public static void premain(String options, Instrumentation ins) {
        ins.addTransformer(new CustomTransformer());
    }
    
    
    @Override
    public byte[] transform(ClassLoader loader,
                            String className,
                            Class<?> classBeingRedefined,
                            ProtectionDomain protectionDomain,
                            byte[] classfileBuffer) throws IllegalClassFormatException {

            ClassReader cr = new ClassReader(classfileBuffer);
            ClassWriter cw = new ClassWriter(ClassWriter.COMPUTE_MAXS);

            TimerClassAdapter tca = new TimerClassAdapter(cw);
            cr.accept(tca, ClassReader.EXPAND_FRAMES);

            byte[] bytes = cw.toByteArray();

            return bytes;
    }
    
}

通过instrument可以在类加载时将原始类的字节码装饰成我们需要的样子。并返回新的类到类加载器中。

将代码打包为agent.jar，可以使用如下的命令执行程序：

java -javaagent:agent_jar_path java_app

就这样，使用-javaagent可以在启动应用前调用我们的计时代码插入程序，这样在应用运行时就能同步计算每个方法的执行时间。

另：上面的代码部分摘自我的一个开源项目jspy中，项目目前代码量还比较小，如有兴趣可以参考下。

########

从一段计时代码开始

发表评论取消回复

其他操作

从一段计时代码开始

发表评论 取消回复

其他操作

标签云

发表评论取消回复