关于 @Async JUnit 测试的问题

batizhao 发布于 2020/04/06 13:51
阅读 1K+
收藏 0

@kipeng300 你好,想跟你请教个问题

看到这个:https://my.oschina.net/kipeng/blog/1795537

我的环境 junit5、spring-boot 2.2.5.RELEASE、spring-cloud Hoxton.SR3、Nacos

异步调用另外一个服务写日志,源码是使用 Feign 的,不过 restTemplate 更容易点。

我测试下来,这个线程池配置没起到作用。

线程池

private String threadNamePrefix = "PecadoTask-";
private boolean waitForTasksToCompleteOnShutdown = true;
private int awaitTerminationSeconds = 60;

异步代码

    @EventListener
    @Async
    public void saveLog(SystemLogEvent event) {
        LogDTO logDTO = (LogDTO) event.getSource();
        log.info("async invoke start: {}", logDTO);

        restTemplate.postForEntity("http://system/log", request, ResponseInfo.class);

        log.info("async invoke end.");
    }

可以看到自定义线程池已经起作用了,但是异步任务没有成功

2020-04-06 13:38:55.761  INFO 52135 --- [   PecadoTask-1] m.b.system.api.event.SystemLogListener   : Feign async invoke start: LogDTO(id=null, httpRequestMethod=GET, className=me.batizhao.ims.web.RoleController, classMethod=findRolesByUserId, description=根据用户ID查询角色, parameter={userId=1}, result=ResponseInfo(code=0, message=ok, data=[RoleVO(id=1, name=ROLE_USER), RoleVO(id=2, name=ROLE_ADMIN)]), spend=429, clientId=test, username=admin, url=http://localhost/role, ip=127.0.0.1, time=Mon Apr 06 13:38:55 CST 2020)
2020-04-06 13:38:55.791 DEBUG 52135 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : HTTP POST http://system/log
2020-04-06 13:38:55.826 DEBUG 52135 --- [           main] m.m.a.RequestResponseBodyMethodProcessor : Using 'application/json', given [*/*] and supported [application/json, application/*+json, application/json, application/*+json]
2020-04-06 13:38:55.827 DEBUG 52135 --- [           main] m.m.a.RequestResponseBodyMethodProcessor : Writing [ResponseInfo(code=0, message=ok, data=[RoleVO(id=1, name=ROLE_USER), RoleVO(id=2, name=ROLE_ADMIN)])]
2020-04-06 13:38:55.841 DEBUG 52135 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : Accept=[application/json, application/*+json]
2020-04-06 13:38:55.862 DEBUG 52135 --- [           main] o.s.s.w.header.writers.HstsHeaderWriter  : Not injecting HSTS header since it did not match the requestMatcher org.springframework.security.web.header.writers.HstsHeaderWriter$SecureRequestMatcher@1997784a
2020-04-06 13:38:55.863 DEBUG 52135 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : Writing [LogDTO(id=null, httpRequestMethod=GET, className=me.batizhao.ims.web.RoleController, classMethod=findRolesByUserId, description=根据用户ID查询角色, parameter={userId=1}, result=ResponseInfo(code=0, message=ok, data=[RoleVO(id=1, name=ROLE_USER), RoleVO(id=2, name=ROLE_ADMIN)]), spend=429, clientId=test, username=admin, url=http://localhost/role, ip=127.0.0.1, time=Mon Apr 06 13:38:55 CST 2020)] as "application/json"
2020-04-06 13:38:55.865 DEBUG 52135 --- [           main] o.s.s.w.a.ExceptionTranslationFilter     : Chain processed normally
2020-04-06 13:38:55.865 DEBUG 52135 --- [           main] s.s.w.c.SecurityContextPersistenceFilter : SecurityContextHolder now cleared, as request processing completed
2020-04-06 13:38:56.264 DEBUG 52135 --- [extShutdownHook] o.s.w.c.s.GenericWebApplicationContext   : Closing org.springframework.web.context.support.GenericWebApplicationContext@7af0affa, started on Mon Apr 06 13:38:29 CST 2020, parent: org.springframework.context.annotation.AnnotationConfigApplicationContext@52f57666
2020-04-06 13:38:56.280  INFO 52135 --- [extShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
2020-04-06 13:38:56.295  INFO 52135 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2020-04-06 13:38:56.314  INFO 52135 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.
2020-04-06 13:38:56.316  WARN 52135 --- [   PecadoTask-1] c.n.c.sources.URLConfigurationSource     : No URLs will be polled as dynamic configuration sources.
2020-04-06 13:38:56.316  INFO 52135 --- [   PecadoTask-1] c.n.c.sources.URLConfigurationSource     : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.
Disconnected from the target VM, address: '127.0.0.1:52607', transport: 'socket'

增加代码

    @SneakyThrows
    @AfterEach
    public void sleep() {
        Thread.sleep(10000L);
    }

执行成功了,Log

2020-04-06 13:23:55.666  INFO 51614 --- [   PecadoTask-1] m.b.system.api.event.SystemLogListener   : Feign async invoke start: LogDTO(id=null, httpRequestMethod=GET, className=me.batizhao.ims.web.RoleController, classMethod=findRolesByUserId, description=根据用户ID查询角色, parameter={userId=1}, result=ResponseInfo(code=0, message=ok, data=[RoleVO(id=1, name=ROLE_USER), RoleVO(id=2, name=ROLE_ADMIN)]), spend=246, clientId=test, username=admin, url=http://localhost/role, ip=127.0.0.1, time=Mon Apr 06 13:23:55 CST 2020)
2020-04-06 13:23:55.693 DEBUG 51614 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : HTTP POST http://system/log
2020-04-06 13:23:55.723 DEBUG 51614 --- [           main] m.m.a.RequestResponseBodyMethodProcessor : Using 'application/json', given [*/*] and supported [application/json, application/*+json, application/json, application/*+json]
2020-04-06 13:23:55.725 DEBUG 51614 --- [           main] m.m.a.RequestResponseBodyMethodProcessor : Writing [ResponseInfo(code=0, message=ok, data=[RoleVO(id=1, name=ROLE_USER), RoleVO(id=2, name=ROLE_ADMIN)])]
2020-04-06 13:23:55.735 DEBUG 51614 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : Accept=[application/json, application/*+json]
2020-04-06 13:23:55.753 DEBUG 51614 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : Writing [LogDTO(id=null, httpRequestMethod=GET, className=me.batizhao.ims.web.RoleController, classMethod=findRolesByUserId, description=根据用户ID查询角色, parameter={userId=1}, result=ResponseInfo(code=0, message=ok, data=[RoleVO(id=1, name=ROLE_USER), RoleVO(id=2, name=ROLE_ADMIN)]), spend=246, clientId=test, username=admin, url=http://localhost/role, ip=127.0.0.1, time=Mon Apr 06 13:23:55 CST 2020)] as "application/json"
2020-04-06 13:23:56.180  INFO 51614 --- [   PecadoTask-1] c.netflix.config.ChainedDynamicProperty  : Flipping property: system.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2020-04-06 13:23:56.217  INFO 51614 --- [   PecadoTask-1] c.netflix.loadbalancer.BaseLoadBalancer  : Client: system instantiated a LoadBalancer: DynamicServerListLoadBalancer:{NFLoadBalancer:name=system,current list of Servers=[],Load balancer stats=Zone stats: {},Server stats: []}ServerList:null
2020-04-06 13:23:56.229  INFO 51614 --- [   PecadoTask-1] c.n.l.DynamicServerListLoadBalancer      : Using serverListUpdater PollingServerListUpdater
2020-04-06 13:23:56.530  INFO 51614 --- [   PecadoTask-1] com.alibaba.nacos.client.naming          : new ips(1) service: DEFAULT_GROUP@@system -> [{"clusterName":"DEFAULT","enabled":true,"ephemeral":true,"healthy":true,"instanceHeartBeatInterval":5000,"instanceHeartBeatTimeOut":15000,"instanceId":"192.168.1.6#6000#DEFAULT#DEFAULT_GROUP@@system","ip":"192.168.1.6","ipDeleteTimeout":30000,"metadata":{"preserved.register.source":"SPRING_CLOUD"},"port":6000,"serviceName":"DEFAULT_GROUP@@system","weight":1.0}]
2020-04-06 13:23:56.542  INFO 51614 --- [   PecadoTask-1] com.alibaba.nacos.client.naming          : current ips:(1) service: DEFAULT_GROUP@@system -> [{"clusterName":"DEFAULT","enabled":true,"ephemeral":true,"healthy":true,"instanceHeartBeatInterval":5000,"instanceHeartBeatTimeOut":15000,"instanceId":"192.168.1.6#6000#DEFAULT#DEFAULT_GROUP@@system","ip":"192.168.1.6","ipDeleteTimeout":30000,"metadata":{"preserved.register.source":"SPRING_CLOUD"},"port":6000,"serviceName":"DEFAULT_GROUP@@system","weight":1.0}]
2020-04-06 13:23:56.569  INFO 51614 --- [   PecadoTask-1] c.netflix.config.ChainedDynamicProperty  : Flipping property: system.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2020-04-06 13:23:56.574  INFO 51614 --- [   PecadoTask-1] c.n.l.DynamicServerListLoadBalancer      : DynamicServerListLoadBalancer for client system initialized: DynamicServerListLoadBalancer:{NFLoadBalancer:name=system,current list of Servers=[192.168.1.6:6000],Load balancer stats=Zone stats: {unknown=[Zone:unknown;	Instance count:1;	Active connections count: 0;	Circuit breaker tripped count: 0;	Active connections per server: 0.0;]
},Server stats: [[Server:192.168.1.6:6000;	Zone:UNKNOWN;	Total Requests:0;	Successive connection failure:0;	Total blackout seconds:0;	Last connection made:Thu Jan 01 08:00:00 CST 1970;	First connection made: Thu Jan 01 08:00:00 CST 1970;	Active Connections:0;	total failure count in last (1000) msecs:0;	average resp time:0.0;	90 percentile resp time:0.0;	95 percentile resp time:0.0;	min resp time:0.0;	max resp time:0.0;	stddev resp time:0.0]
]}ServerList:com.alibaba.cloud.nacos.ribbon.NacosServerList@5cda6d9e
2020-04-06 13:23:57.240  INFO 51614 --- [erListUpdater-0] c.netflix.config.ChainedDynamicProperty  : Flipping property: system.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2020-04-06 13:23:57.751 DEBUG 51614 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : Response 200 OK
2020-04-06 13:23:57.755 DEBUG 51614 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : Reading to [me.batizhao.common.core.util.ResponseInfo<?>]
2020-04-06 13:23:57.765  INFO 51614 --- [   PecadoTask-1] m.b.system.api.event.SystemLogListener   : Feign async invoke end.
2020-04-06 13:48:55.807  INFO 52994 --- [erListUpdater-0] c.netflix.config.ChainedDynamicProperty  : Flipping property: system.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647

2020-04-06 13:49:04.595  INFO 52994 --- [      Thread-18] c.n.l.PollingServerListUpdater           : Shutting down the Executor Pool for PollingServerListUpdater
2020-04-06 13:49:04.597 DEBUG 52994 --- [extShutdownHook] o.s.w.c.s.GenericWebApplicationContext   : Closing org.springframework.web.context.support.GenericWebApplicationContext@261b9a37, started on Mon Apr 06 13:48:02 CST 2020, parent: org.springframework.context.annotation.AnnotationConfigApplicationContext@37468787
2020-04-06 13:49:04.611  INFO 52994 --- [extShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
2020-04-06 13:49:04.634  INFO 52994 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2020-04-06 13:49:04.665  INFO 52994 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.
Disconnected from the target VM, address: '127.0.0.1:54186', transport: 'socket'

线程池的配置对 Junit 不起作用。

加载中
0
batizhao
batizhao

我测试下来大概是 ribbon 和 nacos 的原因,如果把代码改成

new RestTemplate().postForEntity("http://localhost:6000/log", request, ResponseInfo.class);

不要去 nacos 拿配置就成功了。

2020-04-06 13:54:51.585  INFO 53269 --- [   PecadoTask-1] m.b.system.api.event.SystemLogListener   : Feign async invoke start: LogDTO(id=null, httpRequestMethod=GET, className=me.batizhao.ims.web.RoleController, classMethod=findRolesByUserId, description=根据用户ID查询角色, parameter={userId=1}, result=ResponseInfo(code=0, message=ok, data=[RoleVO(id=1, name=ROLE_USER), RoleVO(id=2, name=ROLE_ADMIN)]), spend=231, clientId=test, username=admin, url=http://localhost/role, ip=127.0.0.1, time=Mon Apr 06 13:54:51 CST 2020)
2020-04-06 13:54:51.623 DEBUG 53269 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : HTTP POST http://localhost:6000/log
2020-04-06 13:54:51.647 DEBUG 53269 --- [           main] m.m.a.RequestResponseBodyMethodProcessor : Using 'application/json', given [*/*] and supported [application/json, application/*+json, application/json, application/*+json]
2020-04-06 13:54:51.648 DEBUG 53269 --- [           main] m.m.a.RequestResponseBodyMethodProcessor : Writing [ResponseInfo(code=0, message=ok, data=[RoleVO(id=1, name=ROLE_USER), RoleVO(id=2, name=ROLE_ADMIN)])]
2020-04-06 13:54:51.669 DEBUG 53269 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : Accept=[application/json, application/*+json]
2020-04-06 13:54:51.675 DEBUG 53269 --- [           main] o.s.s.w.header.writers.HstsHeaderWriter  : Not injecting HSTS header since it did not match the requestMatcher org.springframework.security.web.header.writers.HstsHeaderWriter$SecureRequestMatcher@7c269f21
2020-04-06 13:54:51.684 DEBUG 53269 --- [           main] o.s.s.w.a.ExceptionTranslationFilter     : Chain processed normally
2020-04-06 13:54:51.686 DEBUG 53269 --- [           main] s.s.w.c.SecurityContextPersistenceFilter : SecurityContextHolder now cleared, as request processing completed
2020-04-06 13:54:51.687 DEBUG 53269 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : Writing [LogDTO(id=null, httpRequestMethod=GET, className=me.batizhao.ims.web.RoleController, classMethod=findRolesByUserId, description=根据用户ID查询角色, parameter={userId=1}, result=ResponseInfo(code=0, message=ok, data=[RoleVO(id=1, name=ROLE_USER), RoleVO(id=2, name=ROLE_ADMIN)]), spend=231, clientId=test, username=admin, url=http://localhost/role, ip=127.0.0.1, time=Mon Apr 06 13:54:51 CST 2020)] as "application/json"
2020-04-06 13:54:51.769 DEBUG 53269 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : Response 200 OK
2020-04-06 13:54:51.773 DEBUG 53269 --- [   PecadoTask-1] o.s.web.client.RestTemplate              : Reading to [me.batizhao.common.core.util.ResponseInfo<?>]
2020-04-06 13:54:51.798  INFO 53269 --- [   PecadoTask-1] m.b.system.api.event.SystemLogListener   : Feign async invoke end.

2020-04-06 13:54:52.126 DEBUG 53269 --- [extShutdownHook] o.s.w.c.s.GenericWebApplicationContext   : Closing org.springframework.web.context.support.GenericWebApplicationContext@10f477e2, started on Mon Apr 06 13:54:27 CST 2020, parent: org.springframework.context.annotation.AnnotationConfigApplicationContext@57272109
2020-04-06 13:54:52.142  INFO 53269 --- [extShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
2020-04-06 13:54:52.162  INFO 53269 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2020-04-06 13:54:52.184  INFO 53269 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.
Disconnected from the target VM, address: '127.0.0.1:55511', transport: 'socket'

 

0
BekeyChao
BekeyChao
该评论暂时无法显示,详情咨询 QQ 群:点此入群
0
batizhao
batizhao
该评论暂时无法显示,详情咨询 QQ 群:点此入群
OSCHINA
登录后可查看更多优质内容
返回顶部
顶部
返回顶部
顶部