Administrator
发布于 2021-06-22 / 10566 阅读
196

一次 Bean 创建死循环:@PostConstruct 里的远程调用

现象:发布到 K8s 之后 Pod 一直在重启

周一上午发了个小版本,只改了几行。结果 K8s 里这个 Pod 一直 CrashLoopBackOff,被杀了五次。

$ kubectl get pod -n prod | grep order
order-service-7d9f8b6c5-x2m4p   0/1   Running             3     4m12s

$ kubectl describe pod order-service-7d9f8b6c5-x2m4p
...
    Liveness:  http-get http://:8080/actuator/health/liveness delay=60s timeout=3s period=10s
    Readiness: http-get http://:8080/actuator/health/readiness delay=30s timeout=3s period=10s
    State:    Waiting
    Reason:   CrashLoopBackOff
    Last State: Terminated
    Reason:   Error
    Exit Code: 143

Exit Code 143 是 SIGTERM,也就是探针超时被 K8s 杀掉的。liveness 从 60 秒开始探测,说明服务 90 秒都没起来。本地启动只要 25 秒。

排查:卡在哪一步

把探针时间临时放宽,让 Pod 活着,进去看线程栈:

$ kubectl exec -it order-service-7d9f8b6c5-x2m4p -- jcmd 1 Thread.print

找到 main 线程:

"main" #1 prio=5 os_prio=0 tid=0x00007f8c4c009800 nid=0x6 waiting on condition [0x00007f8c53b6e000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(java.base@11.0.11/Native Method)
	- parking to wait for  <0x00000000f5a3c120> (a java.util.concurrent.CountDownLatch$Sync)
	at java.util.concurrent.locks.LockSupport.park(java.base@11.0.11/LockSupport.java:175)
	at java.util.concurrent.CountDownLatch.await(java.base@11.0.11/CountDownLatch.java:231)
	at org.apache.dubbo.config.ServiceConfig.doExport(ServiceConfig.java:376)
	at org.apache.dubbo.config.ServiceConfig.export(ServiceConfig.java:243)
	at com.xxx.order.config.DubboInit.init(DubboInit.java:41)
	at java.lang.reflect.Method.invoke(java.base@11.0.11/Method.java:566)
	at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleElement.invoke(...)
	at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleMetadata.invokeInitMethods(...)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1786)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:602)
	...
	at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:908)

栈看得很清楚:DubboInit 这个类的 @PostConstruct 方法里调了 Dubbo 的服务导出,而导出过程要连注册中心(Nacos),在等一个 CountDownLatch

根因:注册中心地址配错了,而初始化在死等

去看那个类,是一个同事上周加的:

@Component
public class DubboInit {

    @Value("${dubbo.registry.address}")
    private String registryAddress;

    @PostConstruct
    public void init() {
        // 想把 Dubbo 服务在 Spring 容器就绪后、对外提供服务前导出
        ServiceConfig<OrderFacade> service = new ServiceConfig<>();
        service.setInterface(OrderFacade.class);
        service.setRef(orderFacadeImpl);
        service.setRegistry(new RegistryConfig(registryAddress));
        service.export();          // ← 同步阻塞,等注册中心返回
        log.info("dubbo exported");
    }
}

那个环境的 dubbo.registry.address 被配成了 nacos://10.0.3.7:8848,而这个网段的 Nacos 因为网络策略不通。Dubbo 的注册是同步阻塞的,连不上就一直重试(默认重试到 registry.timeout,我们没配,走的是默认的 5000 ms 一次、三次,但 export 内部的 latch 没有兜底超时)。

问题的关键不在地址配错,而在于:初始化方法里做了依赖外部系统的阻塞调用。地址配错只是把它引爆的导火索。哪怕地址是对的,只要 Nacos 抖动,服务启动一样会卡住。我们之前没出事,纯粹是因为 Nacos 一直很稳。

更要命的一点是时序。Spring 的单例 Bean 在 finishBeanFactoryInitialization 阶段串行创建,@PostConstruct 是在这个阶段同步执行的。也就是说:

  1. DubboInit 卡住,DubboInit 这个 Bean 永远创建不完。
  2. ServletWebServerApplicationContextonRefreshfinishBeanFactoryInitialization 之前,所以 Tomcat 端口其实已经开了——这解释了为什么有时候能看到端口在监听但健康接口 404(DispatcherServlet 还没注册)。
  3. liveness 探针打不到,K8s 杀 Pod,重启,再卡住,无限循环。

解决方案

我把它改成了监听容器就绪事件,并且交给独立线程池,失败不影响主流程启动:

@Component
public class DubboInit implements ApplicationListener<ApplicationReadyEvent> {

    private final ExecutorService exportPool =
            new ThreadPoolExecutor(1, 1, 0, TimeUnit.MILLISECONDS,
                    new LinkedBlockingQueue<>(),
                    new ThreadFactoryBuilder().setNameFormat("dubbo-export-%d").build());

    @Override
    public void onApplicationEvent(ApplicationReadyEvent event) {
        // ApplicationReadyEvent 在所有 Bean 初始化完成、WebServer 就绪之后才发
        exportPool.submit(() -> {
            try {
                doExport();
            } catch (Exception e) {
                log.error("dubbo export failed", e);
                // 关键点:不要让异常吞掉,也不要重试到无限
                // 这里可以打到告警,让人工介入
            }
        });
    }
}

三个改动:

  • @PostConstruct 换成 ApplicationReadyEvent。前者在 Bean 创建期执行,后者在容器完全就绪之后。Spring Boot 2.x 里 ApplicationReadyEvent 是在 SpringApplication.run() 返回前发的,此时 Tomcat 已经能接流量了。
  • 阻塞调用扔到独立线程池,主线程不再等它。
  • 失败要显式处理。原来那段代码在 @PostConstruct 里抛异常会导致 Bean 创建失败、容器直接启动失败,反而是好事(fail fast);改成异步之后如果不处理异常,服务"看起来"起来了但其实没注册上,这才是真陷阱。我在 catch 里加了告警。

另外把注册超时显式配上了,避免默认值不清不楚:

dubbo:
  registry:
    address: nacos://10.0.3.7:8848
    timeout: 3000
    check: false     # 注册中心连不上时不要阻断启动

顺带:同类问题的检查清单

改完之后我把整个项目扫了一遍,凡是在初始化阶段做外部调用的地方都列出来:

$ grep -rn "@PostConstruct\|InitializingBean\|@Bean(initMethod" --include=*.java src/main | wc -l
18

18 处里有 2 处有问题,一个是启动时预热本地缓存(调了 Redis),另一个是拉取配置中心的全量配置。前者改成懒加载 + CommandLineRunner,后者加了 3 秒超时。

判断标准很简单:初始化方法里只能做内存操作,任何涉及网络、文件、锁、等待其他线程的操作都应该挪走。需要"启动后执行"的话,Spring 给了几个更合适的位置:

方式执行时机适合做什么
@PostConstructBean 属性注入后,容器初始化中参数校验、构建内存数据结构
InitializingBean同上同上,侵入 Spring API,不如前者
ApplicationRunner / CommandLineRunner容器刷新完成后,WebServer 已就绪预热缓存、注册服务,抛异常会中断启动
ApplicationReadyEvent所有 Runner 执行完对外注册、发启动通知
@EventListener(ApplicationReadyEvent.class) + 异步同上,异步线程非关键的外部依赖初始化

写在后面

现在回头看,《一次 Bean 创建死循环:@PostConstruct 里的远程调用》本身不算多难,难的是线上真出问题那十分钟里的判断。经验都是这么来的。

参考