系列一：进程活着、接口不动——Spring Boot 假死取证与 init.d 脚本改造

Cold 发布于 20 天前 20 次阅读 3176 字 预计阅读时间: 14 分钟 运维笔记

这是一个持续了几个月的老问题：Spring Boot 应用跑着跑着就"假死"——进程在、端口在听、CPU 不高，但接口就是不动。每次都被当成偶发，重启一下先恢复，然后等着下一次。

真正的转折点发生在一次现场没有被破坏的时候。这篇记录三件事：怎么在没有诊断工具的环境下取证、怎么在双实例同机的情况下安全地认领进程，以及一个把启动动作悄悄吃掉的 setsid 陷阱。

系列共两篇。这篇讲应用侧；数据库备份改造另见《系列二：MySQL 备份从"落盘再搬"到"流式直备"》。文中 IP、主机名、密码均已脱敏。

一、环境

角色 配置 关键事实
应用服务器 app-01 16 核 / 62.7G / CentOS 7.9 同一台机器跑两个实例：node01(8887) 与 node02(9997)，同一份 war
数据库服务器 db-01 16 核 / MySQL 8.0.22 另见系列二
测试机 test-01 / test-02 4 核 7.6G / 8 核 15.3G 配置差异极大，参数不可照抄

应用打成 war，用 WarLauncher 启动，由 SysV init.d 脚本管理。三台机器 JDK 都是 8，但包装方式不同——这一点后面会变成区分排查手段的分水岭。

二、三步排除法：先证明"不是那些原因"

告警是监控每 30 秒探端口，某天开始报 端口 8887 无监听。登上机器：

ps -ef | grep [W]arLauncher
cold  11346 11344  2 Jul17 ?   2-20:11:03 java -Djava.io.tmpdir=/home/cold/tmp1 -cp srm ...WarLauncher
cold  31861 31858 10 17:57 ?   00:19:16 /usr/lib/jvm/.../jre/bin/java -Djava.io.tmpdir=/home/cold/tmp ...

进程在、CPU 累计时间也不低，但业务不响应。这类问题不要一上来就猜代码，先把三类常见原因排除掉：

  1. 崩溃：查 hs_err_pid*.log、*.hprof、OutOfMemoryError。本例全都没有。
  2. GC 风暴：看线程 CPU 排行里 GC task thread 的位置。本例连前 15 名都没进，进程平均 CPU 只有 2.9%。
  3. 被重启：查 crontab、/etc/cron.d、init.d 里的定时重启。本例没有。

三类都排除后，剩下的基本就是阻塞型假死：线程都堵在某个下游调用或锁上，CPU 自然是闲的。

教训一：CPU 低不等于没故障。 假死时 CPU 往往是闲的，用 CPU 高低判断健康度会完全失效。

三、没有 jstack 怎么取证

登上去才发现，生产这台只装了 java-1.8.0-openjdk 运行时包，jstack / jstat / jmap 全都不存在（属于 -devel 包）。而现场约定"不改任何生产配置"，装包这条也堵死了。

先确认"这台到底有没有诊断能力"，一条命令：

readlink -f /proc/<pid>/exe
  • 结果以 /jre/bin/java 结尾 → 只有运行时，工具全无，只能读 /proc 或 kill -3
  • 结果以 /bin/java 结尾 → 完整 JDK，jstack/jstat/jmap/jcmd 直接可用

这个差别极大：同一套应用在测试机上 jstat -gcutil 能直接给 FGC 次数和停顿占比，生产机上连这个数都拿不到。所以不要把测试环境验证过的排查步骤直接搬到生产。

3.1 用 kill -3 抓线程栈

kill -3 就是 SIGQUIT，是 JVM 内建能力，不需要任何工具，也不会终止进程——它只把线程栈打到 stdout（也就是日志文件）。因为日志是追加写，需要先记字节偏移再切片，否则分不清哪段是本次的：

OFF=$(wc -c < /app/work/system.log)
kill -3 <pid>
sleep 6
tail -c +$((OFF+1)) /app/work/system.log > /tmp/dump.txt
wc -l /tmp/dump.txt

抓两轮、间隔 10 秒。两轮位置都不变的线程，就是卡住的那批。这比"看谁在跑"有效得多——正常线程两次快照位置不同，卡死的线程一动不动。

3.2 用 /proc 做线程级 CPU 排行

没有 top -H 也能拿到线程名和 CPU 时间：

for t in /proc/<pid>/task/*; do
  echo "$(awk '{sub(/^[0-9]+ \(.*\) /,""); split($0,a," "); print a[12]+a[13]}' $t/stat) $(cat $t/comm)"
done | sort -rn | head -20

sub(/^[0-9]+ \(.*\) /,"") 这一步不能省：/proc/<pid>/stat 的第二个字段是 (comm)，而 Java 线程名允许带空格，直接按空格切字段会整体错位，算出来的 CPU 时间是错的。

本例的结果很有指向性：10 个 redisson-timer-* 线程霸占 CPU 榜首，各 2600～2800 秒；同时 600 多个线程停在 sun.misc.Unsafe.park。顺着查下去，最终定位到一段业务代码：在 Tomcat 请求线程里做 300 秒超时轮询，每轮 Thread.sleep(6000)。Tomcat 默认 200 个工作线程，按 1.5 请求/秒的速度消耗，几分钟就耗尽——对外表现就是"不响应"，而 CPU 依然闲着。

取证顺序建议：先 kill -3（零成本、无副作用、拿到全量栈），再按线程名找热点，最后回到代码。反过来先读代码，会在大工程里迷路。

四、双实例同机：按端口认进程，别按命令行认

这台机器有个坑：两个实例的启动命令都包含 -cp srm org.springframework.boot.loader.WarLauncher，所以

ps -ef | grep "srm org.springframework.boot.loader.WarLauncher"

会同时返回两个 PID。原来的 init.d 脚本里正好有这么一个 getpid()，只是从来没被调用过——一旦有人"顺手"让 stop 用上它，就会把兄弟实例一起杀掉。

正确的识别是端口 + 工作目录双校验：

port_pids() {
    ss -lntp 2>/dev/null | awk -v p=":${PORT}" '$4 ~ p"$"' \
        | grep -o 'pid=[0-9]*' | cut -d= -f2 | sort -u
}

is_ours() {
    [ "$(readlink -f /proc/$1/cwd 2>/dev/null)" = "${PROG_BASE}" ]
}

两道锁：端口说明"它在这个位置上"，/proc/<pid>/cwd 说明"它确实是我这个目录启动的"。两个都成立才动手。另外 pgrep -f WarLauncher 这类按名字兜底的写法必须整个删掉——它在多实例环境里一定会误伤。

教训二：任何"按命令行匹配进程"的逻辑都是定时炸弹。 整个 stop 链路必须能回答一个问题：凭什么确定这个 PID 是我的？答不上来就不该有 kill。

五、init.d 脚本的六个通病

两个实例的脚本几乎一模一样，问题也一模一样：

# 问题 后果
1 restart() 里只调 start()，从不 stop 重启一次多一个 JVM，全抢同一个端口，其余空转吃内存
2 status 分支是空的，返回 0 永远"看起来成功"，自动化脚本被骗
3 getpid() 定义了但从未调用，且靠字符串匹配 白写；谁用它谁误杀兄弟实例
4 没有 stop 只能 kill -9，没有优雅停机
5 export server.tomcat.baseDir=... 变量名带点号，bash 直接报 not a valid identifier，从未生效
6 nohup 脚本 > system.log 覆盖写，每次启动清空历史，故障现场直接丢

另外 export JAVA_HOME=... 也是无效的：su - 是 login shell，会把环境全部重置，子进程根本看不到父 shell 的 export。正确做法是不依赖环境变量，直接用绝对路径：

JAVA_BIN=""
if [ -x /usr/bin/java ]; then
    JAVA_BIN=$(readlink -f /usr/bin/java)
elif command -v java >/dev/null 2>&1; then
    JAVA_BIN=$(readlink -f "$(command -v java)")
fi
[ -n "${JAVA_BIN}" ] && [ -x "${JAVA_BIN}" ] || { echo "找不到 java"; exit 1; }

再用 exec 让脚本 PID 就是 java PID，进程树干净：

exec "${JAVA_BIN}" -Djava.io.tmpdir=${TMPDIR_APP} ... -cp srm org.springframework.boot.loader.WarLauncher

原来脚本末尾还有一句 cd ~。因为 java 是前台阻塞的，这行永远执行不到；但它会让脚本退出码永远是 0，把"java 启动失败"这件事彻底掩盖掉。删掉。

5.1 启动等待必须有反馈

改完脚本第一次重启，操作者等了十几秒没输出，以为卡死按了 Ctrl+C，结果服务停着没人管。加三样东西解决：

  • 每 10 秒心跳：已等待 20s / 180s（java PID 已在，尚未监听 9997），看得见在动
  • 早失败判定：心跳时顺便查本实例 java 是否还在，若启动脚本已报错退出，20 秒内就报失败并打印日志尾部，不用干等 180 秒
  • trap INT：真被 Ctrl+C 打断时，至少提示"启动仍在后台继续，请用 status 确认"

还有一个独立的 srm-launch.log 记录 su - 这一层的输出。su - 失败发生在应用日志之前，不单独记就完全静默——这正是原脚本"看起来成功、实际没起来"的根源。

六、setsid 陷阱：启动动作被悄悄吃掉

为了防止 Ctrl+C 打断启动，我一度把启动语句包了一层：

setsid su "$OWNER" -c "cd $BASE && exec nohup $START_SCRIPT >> $LOG 2>&1" </dev/null >/dev/null 2>&1 &

结果在测试机上，启动根本没有发生：日志一行没写，进程也没起。

排查过程值得记一笔：sudo setsid su - cold -c 'echo B_OK' 单独跑是正常的，所以单点测试完全测不出来。最后是靠"脚本里第一个写动作"定位的——脚本第一件事是 mkdir -p work/logs，而那个目录的时间戳是几小时前手工启动留下的，说明脚本压根没被执行。

换成朴素写法就好了：

su - "$OWNER" -c "cd $BASE && nohup $START_SCRIPT >> $LOG 2>&1 &" </dev/null >> "$LAUNCH_LOG" 2>&1

而且那层 setsid 本来就不必要：末尾的 & 会让 java 在非交互 shell 里成为异步任务，bash 会自动给它忽略 SIGINT，Ctrl+C 保护天然就有。

教训三：验证"脚本有没有执行过"，看它第一个写动作的时间戳，别盯日志内容。 日志没内容可能是"没跑"，也可能是"跑了没输出"，这两种情况的处理方向完全相反。

七、被忽视的杀手：每天 5GB 的日志

排查中顺手 ls -l 了一下应用日志，发现它已经 693MB，mtime 就是当前时刻。用 10 秒增量实测：

s1=$(stat -c %s /app/work/system.log); sleep 10
s2=$(stat -c %s /app/work/system.log)
echo "10s 增长 $(( (s2-s1)/1024 )) KB → 日均 $(( (s2-s1)*8640/1048576 )) MB"

约 60KB/s，日均 5GB，而根分区只剩 30G——不到一周就会写满。写满之后 Spring Boot 写日志失败、hs_err 写不出来，会比"假死"更难查。

更关键的是内容：几乎全是 ERROR 级别，但打的都是正常业务流程——WebSocket 连接/断开、整段报价 JSON、短信回执、"准备保存/保存成功"这类步骤日志。日志膨胀的根因是级别用错，轮转只是止痛药。

7.1 原地截断为什么是安全的

这个日志是 init.d 用 >> 打开的，文件描述符带 O_APPEND。每次写都会落到当前文件末尾，所以原地清空不会产生"空洞文件"：

tail -c 52428800 /app/work/system.log > /app/work/system.log.keep.$(date +%Y%m%d_%H%M)
truncate -s 0 /app/work/system.log

先留 50MB 尾部当证据，再清空。

但绝对不能用 mv。 mv 之后进程的文件描述符还指着改名后的 inode，会继续往旧文件写，新的 system.log 根本不会被创建——这也是很多人"做了轮转却没效果"的原因。

八、本篇复盘清单

  • 先取证，再重启。 挂死的现场只有一次，重启就没了。kill -3 成本极低、无副作用。
  • 判断 JDK 能力看 /proc/<pid>/exe。 以 jre/bin/java 结尾说明只有运行时，别去找 jstack。
  • 进程身份用两个维度确认。 端口 + /proc/<pid>/cwd，比任何命令行匹配都可靠。
  • 脚本改完要验证"实际生效"。 权威依据是 /proc/<pid>/cmdline（实际参数）和 initd 里的 START_SCRIPT=（实际调用的文件），不是 cat 文件名。
  • 日志级别是容量问题。 正常流程不要打 ERROR；同步写 stdout 在高并发下会变成 I/O 瓶颈。
  • 覆盖率验证不了的问题，靠"第一个写动作"定位。 mkdir、touch 这类副作用比日志更早出现。

下一篇换一个战场：同一批服务器上，MySQL 备份每天在数据盘上生成几 GB 临时文件，随时可能把盘撑爆。改造的关键不是换工具，而是先把"备份最终要存在哪"想清楚。

和喜欢的一切在一起~
最后更新于 2026-10-21