test4j导致Load飙高排查

记一次test4j导致CPU飙高的事故

在使用Jenkins构建工程时出现服务器Load不断飙升的现象，导致构建无法正常进行，查看构建日之后发现一些应用处出现OOM的状况。
于是，我就开始查找原因的漫漫长征路。

首先简单了解下test4j初始化过程(忽略读取相关配置及之前)。

Test4jCore->CoreModule:1.initSingletonInstance()
CoreModule->ConfigurationLoader:2.loading()\n加载系统信息\n模块信息\n配置信息（比如：数据库）\n等
CoreModule->ConfigHelper:3.logLevel()\n设置打印消息级别
CoreModule->CoreModule:4.new CoreModule()

CoreModule时序列图

CoreModule->ModulesLoader:1.load()\n加载test4j模块并进行初始化(init)\n初始化Module管理器，主要管理Module监听器
note right of ModulesLoader:相关模块参见test4j-default.properties
CoreModule->CoreModule$CoreModuleListener:2.new CoreModule$CoreModuleListener()
CoreModule->3.Module:afterInit()

上面简单列出test4j的初始化流程，那么这次故障原因在哪产生的呢？不着急，容我慢慢道来。

事故现场：在maven执行test生命周期的过程中，发现cpu利用率不断升高，甚至达到700%，load也随之不断飙升。

排查点一：业务需要大量计算。纵观所有单元测试，没有大量数据计算，那么业务本身原因也就排除。

排查点二：load飙高，是否有大量IO等待。查看stack及各个子线程cpu使用率后，确实有一些IO等待（redis读取等待），此点Mark。

排查点三：IO不会造成高cpu使用率，那么最可能的就是GC了。果不其然，4个GC线程cpu使用率均在100%左右。

排查点四：既然GC这么高，会不会是heap给的太小，但查看程序执行日之后基本排除此种可能，因为发现每个测试类开始test4j都会对spring重新初始化。

排查到第四点就有些兴奋了，test4j是有参数可以设定spring容器行为的，@SpringContext注解中，shared属性默认为fasle，即：spring容器在测试类之间并不共享。那么改掉它，重新跑。竟然好了！那么为什么采用默认的shared值会有问题呢？

排查到这里基本可以确定：1.test4j配置有问题；2.test4j自身的BUG

随后查看了test4j的源码，尼玛！！share属性在程序中竟然写死为ture！！test4j一直就是在以共享spring容器的方式运行！！看到这里基本上就可以确定是test4j的问题了，毕竟这个项目最后一次更新停留在了两年前！！

让我们重新审视test4j的启动，发现还并没有涉及到对spring的操作，因为是对spring的多次初始化，所以我们的目光可以聚焦在对SpringModule的处理上。

在test4j中每个Module均包含一个内部监听类，test4j会在不同的测试生命周期点通知到监听类，以便各个Module做出响应的行为。

下面是SpringModule的监听类部分源码：

SpringModule.java

public void beforeClass(Class testClazz) {
	SpringModuleHelper.resetDumpReference();
	SpringInitInvoker.invokeSpringInitMethod(TestContext.currTestedObject());
	//每次切换测试类，都会init，内部是怎么实现的呢？看下段源码
	Test4JSpringContext springContext = SpringModuleHelper.initSpringContext(testClazz, contextFactory);
	MessageHelper.warn("SpringModuleHelper.initSpringContext " + SpringTestedContext.getSpringContext());
    SpringTestedContext.setSpringContext(springContext);
}

Override
public void afterClass(Object testedObject) {
	//释放当前测试类Spring
	SpringTestedContext.removeSpringContext();
}

SpringModuleHelper.java

public static Test4JSpringContext initSpringContext(Class testClazz, ApplicationContextFactory contextFactory) {
	//首先会从test4j自定义的上下文查找spring上下文，没找到进行创建
	Test4JSpringContext springContext = SpringTestedContext.getSpringContext();
    if (springContext != null) {
        return springContext;
    }
    //找出配置@SpringContext
    SpringContext annotation = AnnotationHelper.getClassLevelAnnotation(SpringContext.class, testClazz);
    Class declaredAnnotationClazz = AnnotationHelper.getClassWithAnnotation(SpringContext.class, testClazz);
    if (annotation == null) {
        return null;
    }
    //spring容器是否共享，程序默认为false
    boolean share = annotation.share();
    Test4JSpringContext context = null;
    if (share) {
	    //SHARED_SPRING_CONTEXT以@SpringContext被注解类为key，来实现spring容器共享
        context = SHARED_SPRING_CONTEXT.get(declaredAnnotationClazz);
    }
    if (context == null) {
	    //注意：BUG即将诞生！！！！！！！
        context = newSpringContext(testClazz, contextFactory, annotation);
    }
    if (share) {
        SHARED_SPRING_CONTEXT.put(declaredAnnotationClazz, context);
    }
    //将springContext设置回测试上下文
    SpringTestedContext.setSpringContext(context);
    return context;
}

private static Test4JSpringContext newSpringContext(Class testClazz, ApplicationContextFactory contextFactory, SpringContext annotation) {
    long startTime = System.currentTimeMillis();
    String[] locations = annotation.value();
    boolean allowLazy = annotation.allowLazy();
    Test4JSpringContext springContext = contextFactory.createApplicationContext(Arrays.asList(locations), false, allowLazy);
    //设置Context共享方式，BUG也由此产生了。
    springContext.setShared(annotation.share());
    //test4j对spring进行了封装，内部调用spring方法初始化
    springContext.refresh();
    long duration = System.currentTimeMillis() - startTime;
    MessageHelper.warn(String.format("take %d ms to init spring context for test obejct[%s]", duration,
            testClazz.getName()));
    return springContext;
}


/**
 * 释放测试类的spring容器
 * 
 * @param springContext
 *            AbstractApplicationContext实例，这里定义为Object是方便其它模块脱离spring依赖
 */
public static void closeSpringContext(Object springContext) {
    if (springContext == null) {
        return;
    }
    if (!(springContext instanceof Test4JSpringContext)) {
        String error = String.format("there must be something error, the type[%s] object isn't a spring context.",springContext.getClass().getName());
        throw new RuntimeException(error);
    }
    Test4JSpringContext context = (Test4JSpringContext) springContext;
    //这个方法
    if (context.isShared() == false) {
        context.destroy();
        MessageHelper.warn("close spring context for class:" + TestContext.currTestedClazzName());
    }
}

public class Test4JSpringContext extends ClassPathXmlApplicationContext {
	private boolean shared;
	/**
	 * 设置是否共享spring
	 * 
	 * @param share
	 */
	public void setShared(boolean share) {
		//哈哈哈，作者写了一个低级BUG出来，当你没使用共享方式的时候，恭喜你，你惨了！继续看代码！
	    this.shared = true;
	}
}

此时BUG的全貌出现了，大家仔细看，test4j中默认的shared为false，也就是默认不共享，但是在为Test4JSpringContext设置shared时却写死为true了。我们还记得test4j的每个Module都有一个内部监听类来处理关心的测试中的各个生命周期，在每个测试类开始前（beforeClass），SpringModule负责spring容器的创建（如果需要），在测试结束后（afterClass），负责容器的销毁（如果需要）。

那么问题就在这里，当我们使用默认的shared时，每个测试开始都会创建一个spring容器，这是正常的，因为我们并没有共享spring容器，但是，当测试结束时，本应该根据shared值销毁spring容器，却因为BUG，从Test4JSpringContext中取出的值为true，作孽啊，test4j认为我们是共享的，便保留了当前的spring容器，于是乎，就出现了车祸现场！

小生不才，以上如有描述有误的地方还望各位不吝赐教 !^_^！