「故事会」使用 jmap 和 VisualVM 辅助排查故障

2023-11-27, 星期一, 15:25

JavaTroubleshootingTuning赛博驱鬼故事会

上周碰到了一个问题:

有个项目从 Nacos 读取 cron 表达式执行定时任务。

@Scheduled(cron = "${job.notifypush.timer}")
public void notify() {
    // ...

在 Nacos 控制台修改配置并重启应用后,任务还是在按照旧的 cron 执行。

一开始怀疑有别的服务在运行,没找着,于是打算看下应用到底读到了什么配置。服务器上没有顺手的工具,因此用 jmap 创建堆快照后下载到本地用 VisualVM 来分析。

# use jmap -dump:[live],format=b,file=<file-path> <pid>
jmap -dump:live,format=b,file=/opt/dump.hprof 36061

Spring Boot 项目中的基础定时任务是通过 org.springframework.scheduling.annotation.EnableScheduling 注解开启的。

不停地 Cmd+B (IntelliJ IDEA on macOS)可以看到 @EnableScheduling@Importorg.springframework.scheduling.annotation.SchedulingConfiguration 这个配置类。这个配置类通过 @Bean 注册了一个 org.springframework.scheduling.annotation.ScheduledAnnotationBeanPostProcessor 而后者的核心是 org.springframework.scheduling.config.ScheduledTaskRegistrar

回到 VisualVM,在 Heap Dump 菜单的 Objects 板块搜索名为 ScheduledTaskRegistrar 的类,确实有一个实例。展开其 <fields> 菜单可以看到一个 java.util.ArrayList 类型的名为 cronTasks 的属性,其成员基本都是 org.springframework.scheduling.annotation.Scheduled 修饰的方法。

可以通过列表成员的 runnable 属性判断其对应执行哪一个方法,找到后查看成员的 expression 属性,就可以知道程序读取到的 cron 表达式。

这里的表达式还是旧的配置,看来是 Nacos 配置没有更新成功,那就是另一个恐怖故事了。

这个故事还告诉我们使用 Spring Boot Actuator 之类的工具时要多加注意 /heapdump 之类的端点不要被外部人士访问了(虽然我也不知道那个故事里这个事故是怎么发生的),不然什么秘密都保不住。

你可以在 https://visualvm.github.io/download.html 下载到 VisualVM,jmap 随附在 JDK 中。