记一次微服务启动慢的问题定位
流水账记录一下查找问题的步骤，抛砖引玉，希望对大家有所帮助。
背景
有这么一个微服务，单中心启动需要10分钟，跨中心（数据库与微服务不在同一个中心）启动需要20分钟。甲方老爷们说了，降不到10分钟以内，不接收运维工作，运维工作就都压在项目组头上。
所以，临危受命优化一下。
常规步骤
第一，查看日志，发现大部分时间浪费到了Spring Bean创建和绑定阶段。
第二，查看CPU，使用率不高，只有单线程飙到了60%，偶尔100%，其余线程在打酱油。
所以，
使用arthas工具收集火焰图追踪一下
- 开启profiler，步骤如下：
- attach进程
- profiler start
- 等待，漫长的等待
- 等到微服务启动完成后，执行profiler stop命令
把生成的火焰图拿下来，看一下，泛红的都是Spring反射，其他的看上去都正常的。
是因为bean太多导致的吗？
用jmap -histo看一下对象的个数，发现也还好啊。但是发现有32个AnnotationConfigApplicationContext和32个DefaultListableBeanFactory，这个地方是需要关注一下的。
打通网络，用JDK自带的jvisualvm远程监控一下。
-
收获1
找到了单线程CPU干活，其他线程围观的原因，在Spring初始化。 -
收获2
另外发现，有GC的情况，看了下GC的时间（10s左右），相较于整个启动过程的时间是可以忽略不计，先找其他的问题吧。 -
收获3
通过CPU profile，发现热点代码在spring框架，两个耗时大户消耗了240s宝贵的时间。
LaunchedURLClassLoader.loadClass()
AbstractAutowireCapableBeanFactory.predicateBeanType()
这两个方法不用看源码都知道不是这里有问题，肯定是乱用了。
这种情况下，需要
- 1，找到调用了多少次
- 2，找到是谁调用了，怎么调用的
因为这个项目里面有很多是跨团队提供的【产品】，并没有提供源代码，所以，需要另辟蹊径来找到怎么调用的。
写javaagent，统计一下方法的调用情况。
使用javassist，对上述两个类（LaunchedURLClassLoader和AbstractAutowireCapableBeanFactory）动态插入点代码。因为是调试，所以就很low地用System.out.println把问题代码打印一下就得了。
上面还发现的AnnotationConfigApplicationContext和DefaultListableBeanFactory被重复创建32次的问题，再构造函数里面插入点代码，看一下是哪个地方创建的这两个类。
方法很简单，插入的两行代码如下，请忽略我的粗暴和不优雅。
System.out.println("==>Invoked===>" + beanName);
new Throwable().printStackTrace();
在输出日志中，因为日志太大，先分割，然后再统计
# 分割文件，每100万行一个
split -l 1000000 console.log
# 做去重和统计
ls x* | while read f
do
grep ^"==>Invoked==>" $f > filtered.$f
sort filtered.$f | uniq > uniq.$f
done
wc -l filtered.*
wc -l uniq.*
通过折腾，发现共创建了6300多个Bean（真不算多），但是predicateBeanType被调用了1100万次，这就过分了 。
再通过StackTrace，发现了问题。
问题
-
一、32个ApplicationContext和BeanFactory的问题
这个是由两个方面引发的
1）spring cloud 的feign在创建bean时，由于使用的是NamedContextFactory，所以创建了多个ApplicationContext和BeanFactory，这部分是正常消耗。
2）我们自己写的AutoConfig，通过FeignContext把ApplicationContext和BeanFactory又创建了一边。这部分找相关人员去优化即可。 -
二、preidicateBeanType被调用1100万次的问题
也是由我们自己写的AutoConfiguration导致的，找到相关人员去优化即可。
