<!-- 主要类似与库存扣减 每次-1 type 只有有限的几种且该表一共就几条数据(一种一条记录)--> <!-- 压测时可以认为 type = 1 是写死的 --> update table set field = field - 1 where type = 1 and filed > 1;上述SQL相当于并发操作同一条数据,肯定存在锁等待。日志显示此处的等待耗时占接口总耗时 80% 以上。二话不说先改为敬。因为是压测环境,直接改为异步执行,确认一下效果。
2023-01-04 15:17:05:347 INFO **.**.**.***.50 [TID: 1s22s72s8ws9w00] ********************** 2023-01-04 15:17:05:348 INFO **.**.**.***.21 [TID: 1s22s72s8ws9w00] ********************** 2023-01-04 15:17:05:350 INFO **.**.**.***.47 [TID: 1s22s72s8ws9w00] ********************** 2023-01-04 15:17:05:465 INFO **.**.**.***.234 [TID: 1s22s72s8ws9w00] ********************** 2023-01-04 15:17:05:467 INFO **.**.**.***.123 [TID: 1s22s72s8ws9w00] ********************** 2023-01-04 15:17:05:581 INFO **.**.**.***.451 [TID: 1s22s72s8ws9w00] ********************** 2023-01-04 15:17:05:702 INFO **.**.**.***.72 [TID: 1s22s72s8ws9w00] **********************前三行info日志没有问题,间隔很小。第4 ~ 第5,第6 ~ 第7,第7 ~ 第8 很明显有百毫秒的耗时。检查代码发现,这部分没有任何耗时操作。那么这段时间干什么了呢?发生了线程切换,换其他线程执行其他任务了。(线程太多了)。日志打印太多了,压测5分钟日志量500M。(记得日志打印太多是有很大影响的)。STW。(但是日志还在输出,所以前两种可能性很高,而且一般不会停顿百毫秒)。
然后,拆线程 @Async 注解使用线程池,控制代码线程池数量(之前存在3个线程池,统一配置的核心线程数为100)结合业务,服务总核心线程数控制在50以内,同步增加阻塞最大大小。结果还可以,提升了50,接近200了。
"http-nio-6071-exec-9" #82 daemon prio=5 os_prio=0 tid=0x00007fea9aed1000 nid=0x62 runnable [0x00007fe934cf4000] java.lang.Thread.State: RUNNABLE at org.springframework.core.annotation.AnnotationUtils.getValue(AnnotationUtils.java:1058) at org.springframework.aop.aspectj.annotation.AbstractAspectJAdvisorFactory$AspectJAnnotation.resolveExpression(AbstractAspectJAdvisorFactory.java:216) at org.springframework.aop.aspectj.annotation.AbstractAspectJAdvisorFactory$AspectJAnnotation.<init>(AbstractAspectJAdvisorFactory.java:197) at org.springframework.aop.aspectj.annotation.AbstractAspectJAdvisorFactory.findAnnotation(AbstractAspectJAdvisorFactory.java:147) at org.springframework.aop.aspectj.annotation.AbstractAspectJAdvisorFactory.findAspectJAnnotationOnMethod(AbstractAspectJAdvisorFactory.java:135) at org.springframework.aop.aspectj.annotation.ReflectiveAspectJAdvisorFactory.getAdvice(ReflectiveAspectJAdvisorFactory.java:244) at org.springframework.aop.aspectj.annotation.InstantiationModelAwarePointcutAdvisorImpl.instantiateAdvice(InstantiationModelAwarePointcutAdvisorImpl.java:149) at org.springframework.aop.aspectj.annotation.InstantiationModelAwarePointcutAdvisorImpl.<init>(InstantiationModelAwarePointcutAdvisorImpl.java:113) at org.springframework.aop.aspectj.annotation.ReflectiveAspectJAdvisorFactory.getAdvisor(ReflectiveAspectJAdvisorFactory.java:213) at org.springframework.aop.aspectj.annotation.ReflectiveAspectJAdvisorFactory.getAdvisors(ReflectiveAspectJAdvisorFactory.java:144) at org.springframework.aop.aspectj.annotation.BeanFactoryAspectJAdvisorsBuilder.buildAspectJAdvisors(BeanFactoryAspectJAdvisorsBuilder.java:149) at org.springframework.aop.aspectj.annotation.AnnotationAwareAspectJAutoProxyCreator.findCandidateAdvisors(AnnotationAwareAspectJAutoProxyCreator.java:95) at org.springframework.aop.aspectj.autoproxy.AspectJAwareAdvisorAutoProxyCreator.shouldSkip(AspectJAwareAdvisorAutoProxyCreator.java:101) at org.springframework.aop.framework.autoproxy.AbstractAutoProxyCreator.wrapIfNecessary(AbstractAutoProxyCreator.java:333) at org.springframework.aop.framework.autoproxy.AbstractAutoProxyCreator.postProcessAfterInitialization(AbstractAutoProxyCreator.java:291) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsAfterInitialization(AbstractAutowireCapableBeanFactory.java:455) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1808) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:620) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542) at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:353) at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:233) at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveNamedBean(DefaultListableBeanFactory.java:1282) at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveNamedBean(DefaultListableBeanFactory.java:1243) at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveBean(DefaultListableBeanFactory.java:494) at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBean(DefaultListableBeanFactory.java:349) at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBean(DefaultListableBeanFactory.java:342) at cn.hutool.extra.spring.SpringUtil.getBean(SpringUtil.java:117) ...... ......上边的堆栈发现了一个点:在执行getBean的时候,执行了createBean方法。我们都知道Spring托管的Bean都是提前实例化好放在IOC容器中的。createBean要做的事情有很多,比如Bean的初始化,依赖注入其他类,而且中间还有一些前后置处理器执行、代理检查等等,总之是一个耗时方法,所以都是在程序启动时去扫描,加载,完成Bean的初始化。
<!--BeanUtils 是 hutool 工具类。也是从IOC容器获取Bean 等价于 @Autowired 注解 --> RedisTool redisTool = BeanUtils.getBean(RedisMaster.class);而RedisMaster类
@Component @Scope("prototype") public class RedisMaster implements IRedisTool { // ...... }没错就是用了多例。而且使用的地方是Redis(系统使用Jedis客户端,Jedis并非线程安全,每次使用都需要新的实例),接口对Redis的使用还是比较频繁的,一个接口得有10次左右获取Redis数据。也就是说执行10次左右的createBean逻辑 ...
// 堆代码 duidaima.com long start = System.currentTimeMillis(); // ...... long end = System.currentTimeMillis(); long runTime = start - end;或者Hutool提供的StopWatch:
StopWatch watch = new StopWatch(); watch.start(); // ...... watch.stop(); System.out.println(watch.getTotalTimeMillis());而这种在并发量高的情况下,对性能影响还是比较大的,特别在服务器使用了一些特定时钟的情况下。这里就不多说,感兴趣的可以自行搜索一下。
结果是好的,过程是曲折的。总的来说还是知识的欠缺,文章看起来还算顺畅,但都是事后诸葛亮,不对,应该是时候臭皮匠。基本都是边查资料边分析边操作,前后花费了4天时间,尝试了很多。