启动 96 秒到 14 秒:Spring Boot 启动慢的分层排查

扩容时新 Pod 八十秒才 Ready,HPA 跟不上流量。从 Bean 实例化打点到收窄扫描包,再到 AlwaysPreTouch 与 JMX,每一层的收益和风险都记下来了。

大促前扩容演练,我们准备把订单服务从 12 个实例扩到 40 个。压测一开始就卡住了:HPA 触发扩容,新 Pod 起来了,但一直不是 Ready,等到第八十秒才开始接流量。整个扩容窗口从预期的 40 秒拉长到接近两分钟,压力全压在现有实例上。

看启动日志,Started OrderApplication in 96.412 seconds。这个数字在开发环境是 11 秒,测试环境 20 秒,生产环境 96 秒。同一个 jar,同一份配置结构,差出八倍。

启动慢在平时不痛不痒,因为实例常年不重启。但它有两个直接代价:一是扩容跟不上流量,二是发版时的不可用窗口变长。我们那次把目标定成 15 秒以内,下面是从 96 秒到 14 秒的完整过程。

一、先分段,别急着猜

启动耗时的排查最忌讳「凭感觉猜」。Spring Boot 的启动可以切成几段:JVM 与类加载、容器初始化(ApplicationContext 创建)、Bean 实例化、Web 容器启动、以及 ApplicationRunner/CommandLineRunner。每段的耗时特征完全不同。

第一步是看自动配置到底加载了什么。用 java -jar order-service.jar --debug 启动,会输出完整的 ConditionEvaluationReport,把 matched 和 did not match 两类分别计数就能知道装配规模。

结果是 matched: 187,did not match: 412。187 个自动配置生效,这个数字偏高——一个纯粹的订单服务不该装配这么多东西。

第二步是拿到分阶段耗时。Spring Boot 自带 BufferingApplicationStartup,可以记录每个 ApplicationStartupStep 的耗时,这是最权威的口径:

@SpringBootApplication
public class OrderApplication {
    public static void main(String[] args) {
        SpringApplication app = new SpringApplication(OrderApplication.class);
        app.setApplicationStartup(new BufferingApplicationStartup(2048));
        app.run(args);
    }
}

配合 Actuator 的 startup 端点(需要暴露),可以拿到结构化的步骤树:

curl -s http://localhost:8080/actuator/startup | \
  jq -r '.timeline.events[]
    | select(.duration > 200000000)
    | "\(.duration/1000000 | floor)ms  \(.startupStep.name)"' | sort -rn | head -20

duration 单位是纳秒,200000000 就是 200ms。输出把耗时超过 200ms 的步骤全列出来了,这一步让我直接看到三个大头:spring.beans.instantiate 累计 41 秒,spring.context.refresh 里有一部分 23 秒,还有一个我没想到的 application.run 之后的 12 秒。

二、Bean 实例化占 41 秒

spring.beans.instantiate 是个聚合步骤,要往下钻。我写了个 BeanPostProcessor 打点,记录每个 Bean 从 postProcessBeforeInitialization 到 postProcessAfterInitialization 的耗时:

@Component
public class BeanTimingPostProcessor implements BeanPostProcessor {
    private static final Logger log = LoggerFactory.getLogger(BeanTimingPostProcessor.class);
    private final Map<String, Long> startAt = new ConcurrentHashMap<>();

    @Override
    public Object postProcessBeforeInitialization(Object bean, String beanName) {
        startAt.put(beanName, System.nanoTime());
        return bean;
    }

    @Override
    public Object postProcessAfterInitialization(Object bean, String beanName) {
        Long start = startAt.remove(beanName);
        if (start != null) {
            long ms = (System.nanoTime() - start) / 1_000_000;
            if (ms > 100) {
                log.warn("SLOW BEAN {} {}ms", beanName, ms);
            }
        }
        return bean;
    }
}

注意这个打点只统计初始化回调的耗时(@PostConstruct、InitializingBean),不包含构造和依赖注入,但对「启动时偷偷做重活」的场景足够用了。

日志里最刺眼的一条:

SLOW BEAN dubboConfigBean 18240ms
SLOW BEAN redisTemplate 9103ms
SLOW BEAN orderEsClient 6310ms

dubboConfigBean 十八秒——它在 @PostConstruct 里同步去注册中心拉配置,注册中心跨机房,一次 RTT 80ms,要拉的配置项有几百个,串行拉完就是十几秒。这类「启动时同步做远程调用」是最常见的启动杀手,因为它的耗时完全取决于网络。

redisTemplate 九秒更离谱,追进去发现是有人在 @PostConstruct 里做了一次 keys * 预热缓存。生产环境 Redis 有 400 多万个 key,keys * 直接把实例 CPU 打满,同时也把应用启动拖住了。

orderEsClient 六秒是建索引连接池,这个还算合理,可以异步化。

三、@ComponentScan 扫得太宽

除了单个 Bean 慢,还有一个「总量」问题。我们的启动类是这样的:

@SpringBootApplication(scanBasePackages = "com.example")
public class OrderApplication { }

com.example 是整个公司的基础包名,下面挂了二十多个模块的代码,其中大部分是订单服务根本用不到的(用户中心、财务、风控、消息推送……)。类路径扫描要把这些包下所有 class 读一遍、解析注解、判断是不是候选 Bean。

用 -verbose:class 数一下加了多少类:

java -verbose:class -jar order-service.jar 2>&1 | grep -c "Loaded"
# 18422

一万八千个类。而实际的 @Component 只有 300 多个。也就是说绝大部分扫描是纯浪费。

改成精确的包列表:

@SpringBootApplication(scanBasePackages = {
    "com.example.order",
    "com.example.common.web",
    "com.example.common.mybatis"
})

类加载数降到 9100 左右,spring.context.refresh 这一段直接少了 9 秒。

这里有个取舍要注意:scanBasePackages 收窄之后,如果某个 @Configuration 在范围外,会静默失效——应用能起来,但功能缺失,比启动失败更难查。我们的做法是先收窄,跑完整回归,再把漏掉的包补回去。回归用例覆盖了所有对外接口,这一步不能省。

四、懒加载不是万灵药

查到这里,一个很自然的想法是开全局懒加载:

spring.main.lazy-initialization=true

试了一下,启动从 96 秒降到 31 秒,效果看起来很好。但我建议不要在生产上直接开,原因有三个。

第一,启动时间只是被挪到了第一次请求。用户第一次访问某个接口时,那一整条链上的 Bean 才开始初始化,响应时间会突然变成几秒。我们压测时看到首个订单查询接口 P99 直接冲到 4.2 秒,比启动慢更难接受。

第二,懒加载会让配置错误延迟暴露。一个依赖不存在的 Bean、一个连不上的数据源,原本启动就失败,开了懒加载之后要等到有人访问才发现。

第三,@Lazy 和作用域代理在一起时行为微妙,@Transactional 的代理可能在懒初始化时错过某些 BeanPostProcessor,出问题极难定位。

我们最后只对三类 Bean 开了局部懒加载:

// 明确知道「启动时不需要、首次使用时才需要」的重组件
@Lazy
@Bean
public ReportExportClient reportExportClient(...) { ... }

@Lazy
@Service
public class EsAggregationService { ... }

也就是报表导出、ES 聚合查询这类低频且重的服务。核心交易链路上的 Bean 全部保持急加载。

五、JIT 与类加载的边际收益

前面几步做完,启动降到 34 秒。继续往下压,进入 JVM 层面。

第一件事是开 CDS(Class Data Sharing)。JDK 12 之后有默认的 classes.jsa,但只覆盖 JDK 自身的类,应用类要自己归档,用 -XX:DumpLoadedClassList 导出类列表,再 -Xshare:dump 生成,之后启动带 -XX:SharedArchiveFile 即可。

CDS 省了大概 2.5 秒,主要来自类加载时的解析和验证。收益不算大,但成本极低,值得做。

第二件事是调 JVM 参数。这里踩了个坑:

# 出问题的参数组合
java -Xms4g -Xmx4g -XX:+UseG1GC -XX:MaxGCPauseMillis=100 -XX:+AlwaysPreTouch ...

AlwaysPreTouch 会在启动时把整个 4 GB 堆的每一页都真实分配并清零。在容器里,这个动作要花 6 到 8 秒,而且它发生在 Spring 启动之前,日志里完全看不出来。去掉之后启动直接快 7 秒。

AlwaysPreTouch 的意义是避免运行期缺页中断导致的延迟毛刺,对于长时间运行的稳定服务有价值。但对「频繁重启扩容」的容器化部署,启动开销的代价更明显。我们最后的方案是:保留 AlwaysPreTouch,但把 Xms 从 4g 降到 2g(实际使用峰值 1.6g),用更小的堆换更短的预触碰时间。

六、最终结果与配置

优化项 累计启动耗时 单项收益 风险
基线 96.4s — —
去掉 @PostConstruct 里的远程调用与 keys * 58.1s -38.3s 低,改为异步预热
收窄 scanBasePackages 49.2s -8.9s 中,需完整回归
移除 AlwaysPreTouch 并降 Xms 42.0s -7.2s 低,接受轻微毛刺
局部 @Lazy(报表、ES 聚合) 33.6s -8.4s 低,避开核心链路
开 CDS 31.1s -2.5s 低
移除 3 个无用 starter 27.8s -3.3s 低
spring.jmx.enabled=false、spring.main.keep-alive 调整 14.2s -13.6s 低

最后一行收益这么大有点意外,拆开看主要来自两块:一是 JMX 默认开启会为每个 Bean 注册 MBean,187 个自动配置带来的 Bean 数量下,这一项就要好几秒;二是我们关掉了 Actuator 里几个昂贵的端点(/actuator/env 的 show-values、/actuator/configprops),它们在启动时会做全量属性收集。

最终的 application.properties 关键片段:

spring.jmx.enabled=false
spring.main.lazy-initialization=false
spring.main.banner-mode=off

management.endpoints.web.exposure.include=health,info,metrics,startup
management.endpoint.configprops.enabled=false
management.endpoint.env.show-values=never

server.tomcat.threads.min-spare=10
server.tomcat.accept-count=200

Tomcat 那两行也是启动优化:min-spare 默认 10,如果配大了会在启动时预创建线程,每个线程要分配栈空间。accept-count 不影响启动,顺手统一了配置。

改完必须做三层验证:启动自检(关键 Bean 是否就绪、数据源与 Redis 是否连通,失败直接让进程退出,不要以「看起来正常」的状态接流量)、全量接口回归(收窄扫描包和 @Lazy 都可能造成功能静默缺失,这一步最耗时也最不能省)、灰度观察(先让两个实例跑 24 小时,对比错误率、P99 与 GC 次数)。我们去掉 AlwaysPreTouch 后 Pause Young 从 12ms 涨到 18ms,在可接受范围内才全量推。

小结

  • 启动耗时先分段再优化:用 BufferingApplicationStartup 配合 /actuator/startup 拿步骤级耗时,比猜快得多。
  • @PostConstruct 里做远程调用是启动慢的头号原因,注册中心拉配置、keys * 预热这类操作必须挪到异步或首次使用时。
  • scanBasePackages 收窄能显著减少类加载量,但会造成范围外的 @Configuration 静默失效,必须配全量回归;用 -verbose:class 数类数量可以量化收益。
  • 全局 spring.main.lazy-initialization=true 只把耗时挪到第一次请求,还会延迟暴露配置错误,不要在生产上开;只对明确低频的重组件加 @Lazy。
  • -XX:+AlwaysPreTouch 会在 Spring 启动前真实分配整个堆,4 GB 堆要花 6–8 秒,容器化频繁重启的场景下这个代价往往不值得。
  • 关掉 spring.jmx.enabled 和昂贵的 Actuator 端点,在 Bean 数量多的项目上收益经常超过几秒。
  • 优化后必须做启动自检 + 全量回归 + 灰度观察,「启动更快但功能缺失」比启动慢严重得多。
查看「Java 与 JVM」全部文章 →

同分类文章

查看 0 评论 0

评论

正在加载评论…

留言提交后自动审核:正常内容立即显示,含敏感信息的会转人工复核。