⭐⭐⭐ Spring Boot 项目实战 ⭐⭐⭐ Spring Cloud 项目实战
《Dubbo 实现原理与源码解析 —— 精品合集》 《Netty 实现原理与源码解析 —— 精品合集》
《Spring 实现原理与源码解析 —— 精品合集》 《MyBatis 实现原理与源码解析 —— 精品合集》
《Spring MVC 实现原理与源码解析 —— 精品合集》 《数据库实体设计合集》
《Spring Boot 实现原理与源码解析 —— 精品合集》 《Java 面试题 + Java 学习指南》

摘要: 原创出处 blog.csdn.net/lkx444368875/article/details/127268108 「凯雄,长沙起风了、」欢迎转载,保留摘要,谢谢!


🙂🙂🙂关注微信公众号:【芋道源码】有福利:

  1. RocketMQ / MyCAT / Sharding-JDBC 所有源码分析文章列表
  2. RocketMQ / MyCAT / Sharding-JDBC 中文注释源码 GitHub 地址
  3. 您对于源码的疑问每条留言都将得到认真回复。甚至不知道如何读源码也可以请教噢。
  4. 新的源码解析文章实时收到通知。每周更新一篇左右。
  5. 认真的源码交流微信群。

一个其他团队的比较老的dubbo服务,spring的版本在3.2.x范围,用的还是spring那一套。

由于这个服务比较核心,而且集成的组件比较多:rabbit、dubbo、es、kafka、zk、redis、cas等等一系列组件,然后开发的痛点就是本地启动时间太慢了,常常耗时接近10分钟、机器配置差点夸张到10+。抱着好奇的心理开始这一次排查之旅。

❝

启动耗时 : Artifact xxxx:war exploded: Deploy took 730,358 milliseconds

优化成果: Artifact xxxx:war exploded: Deploy took 95,078 milliseconds

❞

由于老服务启动日志偏少,索性开始之前使用过的JProfiles来作为本次的分析工具,它可以实时侦测所有代码的运行耗时。对一些启动慢链路追踪有非常好的帮助。

Jprofile - CPU检测

基于Jprofile的使用文章

❝

❞

通过JProfile检测,发现了一个比较耗时的点:就是

这个类的作用是:

// 通过反射判断实例是否存在
public static boolean isPresent(String className, ClassLoader classLoader) {
try {
forName(className, classLoader);
return true;
} catch (Throwable var3) {
return false;
}
}

/**
* The class name of AnnotatedElementUtils that is introduced since Spring Framework 4
*/
public static final String ANNOTATED_ELEMENT_UTILS_CLASS_NAME = "org.springframework.core.annotation.AnnotatedElementUtils";

// 往上追踪的话是查找AnnotatedElementUtils是否存在
ClassUtils.isPresent(ANNOTATED_ELEMENT_UTILS_CLASS_NAME, classLoader)

很显然这个过程就是nacos会判断AnnotatedElementUtils是否存在,通过注释我们可以了解到AnnotatedElementUtils这个类是Spring 4的版本,而这个服务还只是3.2.x,如果这个类没有相当于在扫描bean容器查看nacos相关注解的时候,所有类都会经过classLoader判断一遍,这些基本上都是无效判断,类多了耗时严重。原本想着升级Spring版本,发现牵一发动全身~那既然版本没跟上那么就直接关闭该功能呗,

通过继续往上追踪com.alibaba.spring.util.AnnotationUtils#getAnnotationAttributes到这个类时有一个tryMergedAnnotation属性的判断:

public static AnnotationAttributes getAnnotationAttributes(AnnotatedElement annotatedElement,
Class<? extends Annotation> annotationType,
PropertyResolver propertyResolver,
boolean classValuesAsString,
boolean nestedAnnotationsAsMap,
boolean ignoreDefaultValue,
boolean tryMergedAnnotation,
String... ignoreAttributeNames) {

AnnotationAttributes attributes = null;

if (tryMergedAnnotation) {
attributes = tryGetMergedAnnotationAttributes(annotatedElement, annotationType, propertyResolver,
classValuesAsString, nestedAnnotationsAsMap, ignoreDefaultValue, ignoreAttributeNames);
}

if (attributes == null) {
attributes = getAnnotationAttributes(annotatedElement, annotationType, propertyResolver,
classValuesAsString, nestedAnnotationsAsMap, ignoreDefaultValue, ignoreAttributeNames);
}

return attributes;
}

这个说明只有这个属性为true的时候,才会扫描加载AnnotatedElementUtils,嗯,我们可以自己定义去覆盖原本nacos自动注册的类,然后坑此坑次的在配置文件加上了。

<bean id="annotationNacosInjectedBeanPostProcessor"
class="com.alibaba.nacos.spring.beans.factory.annotation.AnnotationNacosInjectedBeanPostProcessor">
<property name="tryMergedAnnotation" value="false"/>
</bean>

<bean id="nacosValueAnnotationBeanPostProcessor"
class="com.alibaba.nacos.spring.context.annotation.config.NacosValueAnnotationBeanPostProcessor">
<property name="tryMergedAnnotation" value="false"/>
</bean>

嗯,这个问题解决了,开始启动。

效果还是有的,时间减少了40%吧,但还是远远不够,继续观察。

❝

Artifact xxxx:war exploded: Deploy took 462,016 milliseconds

❞

线程等待

通过日志发现经过一段时间后,不打印了。

[2022-09-28 17:15:56.913][ WARN][][][SimpleAsyncTaskExecutor-1][o.s.a.r.l.SimpleMessageListenerContainer|1168]:Consumer raised exception, processing can restart if the connection factory supports it. Exception summary: org.springframework.amqp.AmqpConnectException: java.net.ConnectException: Connection timed out: connect

连接超时,这个一看是rabbitMQ的,我想应该也不会阻塞主线程吧?

这个时候我在想:主线程在干啥呀!?

"RMI TCP Connection(3)-127.0.0.1@1830" daemon prio=5 tid=0x14 nid=NA waiting
java.lang.Thread.State: WAITING
at sun.misc.Unsafe.park(Unsafe.java:-1)
at java.util.concurrent.locks.LockSupport.<obsolete>(LockSupport.java:-1)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328)
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277)
at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$AsyncMessageProcessingConsumer.getStartupException(SimpleMessageListenerContainer.java:992)
at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.doStart(SimpleMessageListenerContainer.java:666)
- locked <0x3314> (a java.lang.Object)
at org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.start(AbstractMessageListenerContainer.java:458)
at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:167)
at org.springframework.context.support.DefaultLifecycleProcessor.access$200(DefaultLifecycleProcessor.java:51)
at org.springframework.context.support.DefaultLifecycleProcessor$LifecycleGroup.start(DefaultLifecycleProcessor.java:339)
at org.springframework.context.support.DefaultLifecycleProcessor.startBeans(DefaultLifecycleProcessor.java:143)
at org.springframework.context.support.DefaultLifecycleProcessor.onRefresh(DefaultLifecycleProcessor.java:108)
at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:945)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:482)

发现线程居然阻塞等待了!!!

通过观察线程栈找到SimpleMessageListenerContainer这个类的getStartupException方法,看到了令我绝望的代码

private final CountDownLatch start = new CountDownLatch(1);

public FatalListenerStartupException getStartupException() throws TimeoutException, InterruptedException {
start.await(60000L, TimeUnit.MILLISECONDS);
return this.startupException;
}

public void run() {
SimpleMessageListenerContainer.this.redeclareElementsIfNecessary();
this.consumer.start();
this.start.countDown();

// 省略
restart(this.consumer);
}

它其实是有唤醒的操作的,但是由于启动不成功,唤醒不了,又触发重试,继续等待。但我没想明白的是这个东西怎么是在主线程做的,也不确定是不是包版本太低的原因。

Rabbit连不上这个其实也是有原因的,因为我们这边的本地的都是连的测试环境的,nacos的测试环境配置是阿里云内网的地址,导致本地肯定是连不上的,所以我找了个公网地址试了一下,发现果然有用。

❝

优化成果: Artifact xxxx:war exploded: Deploy took 95,078 milliseconds

❞

其实还发现了一些其他阻塞,不过都是属于连接方面的,比如zk、数据库等等,目前这个古老的项目1分半也属于偏正常范围吧,主要还是组件太多,代码也多。

好了,本次排查到此为止。排查的手段和方案可以给大家提供一种思路~

文章目录
  1. 1. Jprofile - CPU检测
  2. 2. 线程等待