在使用spring boot框架进行单元测试时,笔者遇到一个问题,每次执行单元测试类时都会重复加载spring上下文,而加载过程通常都非常耗时,这大大增加了整个单元测试的执行时间,加载过程类似下面的日志:
18:58:49,386 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@3f6b0be5 - Registering current configuration as safe fallback point
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.0.3.RELEASE)
18:58:53.463 [main] INFO c.c.hybj.payment.oms.OmsApplication [SpringApplication.java:663] - The following profiles are active: develop
18:58:59.986 [localhost-startStop-1] INFO o.e.plugins.PluginsService [PluginsService.java:176] - no modules loaded
18:58:59.990 [localhost-startStop-1] INFO o.e.plugins.PluginsService [PluginsService.java:179] - loaded plugin [org.elasticsearch.index.reindex.ReindexPlugin]
18:58:59.990 [localhost-startStop-1] INFO o.e.plugins.PluginsService [PluginsService.java:179] - loaded plugin [org.elasticsearch.join.ParentJoinPlugin]
18:58:59.990 [localhost-startStop-1] INFO o.e.plugins.PluginsService [PluginsService.java:179] - loaded plugin [org.elasticsearch.percolator.PercolatorPlugin]
18:58:59.990 [localhost-startStop-1] INFO o.e.plugins.PluginsService [PluginsService.java:179] - loaded plugin [org.elasticsearch.script.mustache.MustachePlugin]
18:58:59.990 [localhost-startStop-1] INFO o.e.plugins.PluginsService [PluginsService.java:179] - loaded plugin [org.elasticsearch.transport.Netty4Plugin]
18:59:01.202 [localhost-startStop-1] INFO i.n.util.internal.PlatformDependent [Netty4InternalESLogger.java:104] - Your platform does not provide complete low-level API for accessing direct buffers reliably. Unless explicitly requested, heap buffer will always be preferred to avoid potential system instability.
18:59:04.242 [main] INFO o.h.jpa.internal.util.LogHelper [LogHelper.java:31] - HHH000204: Processing PersistenceUnitInfo [
name: default
...]
18:59:04.318 [main] INFO org.hibernate.Version [Version.java:45] - HHH000412: Hibernate Core {5.2.17.Final}
18:59:04.321 [main] INFO org.hibernate.cfg.Environment [Environment.java:213] - HHH000206: hibernate.properties not found
18:59:04.371 [main] INFO o.h.annotations.common.Version [JavaReflectionManager.java:66] - HCANN000001: Hibernate Commons Annotations {5.0.1.Final}
18:59:05.006 [main] INFO c.alibaba.druid.pool.DruidDataSource [DruidDataSource.java:930] - {dataSource-1} inited
18:59:05.019 [main] INFO org.hibernate.dialect.Dialect [Dialect.java:157] - HHH000400: Using dialect: org.hibernate.dialect.MySQL5Dialect
18:59:07.961 [main] INFO s.d.s.w.PropertySourcedRequestMappingHandlerMapping [PropertySourcedRequestMappingHandlerMapping.java:69] - Mapped URL path [/v2/api-docs] onto method [public org.springframework.http.ResponseEntity<springfox.documentation.spring.web.json.Json> springfox.documentation.swagger2.web.Swagger2Controller.getDocumentation(java.lang.String,javax.servlet.http.HttpServletRequest)]
18:59:10.598 [main] INFO s.d.s.w.p.DocumentationPluginsBootstrapper [DocumentationPluginsBootstrapper.java:151] - Context refreshed
18:59:10.618 [main] INFO s.d.s.w.p.DocumentationPluginsBootstrapper [DocumentationPluginsBootstrapper.java:154] - Found 1 custom documentation plugin(s)
18:59:10.668 [main] INFO s.d.s.w.s.ApiListingReferenceScanner [ApiListingReferenceScanner.java:41] - Scanning for api listing references
18:59:10.900 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingGET_1
18:59:10.902 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingHEAD_1
18:59:10.903 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPOST_1
18:59:10.904 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPUT_1
18:59:10.905 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPATCH_1
18:59:10.906 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingDELETE_1
18:59:10.907 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingOPTIONS_1
18:59:10.909 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingTRACE_1
18:59:10.932 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingGET_2
18:59:10.933 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingHEAD_2
18:59:10.934 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPOST_2
18:59:10.934 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPUT_2
18:59:10.935 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPATCH_2
18:59:10.936 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingDELETE_2
18:59:10.937 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingOPTIONS_2
18:59:10.937 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingTRACE_2
18:59:10.951 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingGET_3
18:59:10.952 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingHEAD_3
18:59:10.953 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPOST_3
18:59:10.954 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPUT_3
18:59:10.955 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPATCH_3
18:59:10.956 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingDELETE_3
18:59:10.956 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingOPTIONS_3
18:59:10.957 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingTRACE_3
18:59:10.968 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingGET_4
18:59:10.969 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingHEAD_4
18:59:10.969 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPOST_4
18:59:10.970 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPUT_4
18:59:10.970 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPATCH_4
18:59:10.971 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingDELETE_4
18:59:10.971 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingOPTIONS_4
18:59:10.972 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingTRACE_4
18:59:11.025 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingGET_5
18:59:11.027 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingHEAD_5
18:59:11.028 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPOST_5
18:59:11.029 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPUT_5
18:59:11.030 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingPATCH_5
18:59:11.031 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingDELETE_5
18:59:11.032 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingOPTIONS_5
18:59:11.033 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: exportUsingTRACE_5
18:59:11.063 [main] INFO s.d.s.w.r.o.CachingOperationNameGenerator [CachingOperationNameGenerator.java:40] - Generating unique operation named: getResourcesUsingPOST_1
18:59:11.134 [main] INFO c.c.hybj.payment.oms.OmsApplication [StartupInfoLogger.java:59] - Started OmsApplication in 21.61 seconds (JVM running for 23.984)
18:59:11.137 [main] INFO c.c.h.p.f.l.ApplicationStartup [ApplicationStartup.java:42] - ============启动成功==============
18:59:11.137 [main] INFO c.c.h.p.f.l.ApplicationStartup [ApplicationStartup.java:43] - ============当前系统应用的配置环境:develop==============
在查阅了相关资料后,发现是spring在执行单元测试时,会将spring相关配置作为一个唯一的key,将对应上下文放在缓存当中,也就是说,如果每个单元测试类的加载的配置相同,就只会加载一次上下文,而后的执行过程中会从缓存中提取上下文,那么,为什么我的单元测试会每次加载?原因是,我的单元测试继承了同一个基类,而这个基类使用了powermock,在spring的测试策略中,如果有mock存在,单元测试类每次都会重新加载上下文,可以参考[https://github.com/spring-projects/spring-boot/issues/7174]。
那么,如何解决呢?方法也很简单,在基类中去除powermock,在特定需要使用powermock的类中覆写配置,笔者原先的spring测试基类是这样的:
@RunWith(PowerMockRunner.class)
@PowerMockRunnerDelegate(SpringJUnit4ClassRunner.class)
@PowerMockIgnore({"javax.net.ssl.*", "javax.management.*", "javax.crypto.*"})
@SpringBootTest
@PrepareForTest({HttpUtil.class})
public class SpringBaseTest{
.....
}
修改后变成这样:
@SpringBootTest
@RunWith(SpringJUnit4ClassRunner.class)
public class SpringBaseTest{
......
}
然后,在需要使用powermock模拟静态方法的类中做如下配置:
@AutoConfigureMockMvc
@WebAppConfiguration
@RunWith(PowerMockRunner.class)
@PowerMockRunnerDelegate(SpringJUnit4ClassRunner.class)
@PowerMockIgnore({"javax.net.ssl.*", "javax.management.*", "javax.crypto.*"})
@PrepareForTest({HttpUtil.class})
public class WxspAuthenControllerTest extends SpringBaseTest {
.....
}
这样,就可以使得不需要powermock的类使用缓存中的上下文,从而减少整个单元测试的执行时间。