一次典型的"数据库侧只看到错误、不知道是谁在连"的故障定位记录。核心思路:DB 端只能看到来源 IP,真正的凶手要回到应用服务器上按连接反查进程。
说明:本文中主机名、IP、账号、服务名、路径等均已做脱敏处理,仅保留排查逻辑与命令。
一、背景与现象
巡检时在 MySQL 服务器 /var/log/messages 中发现大量重复报错:
Oct 20 00:20:58 DB-SERVER-01 mysqld: 2026-10-20T00:20:58.176589+08:00 27589250 [Note] Access denied for user 'app_user'@'192.0.2.10' (using password: YES)几个关键信息:
| 字段 | 含义 |
|---|---|
Access denied for user 'app_user'@'192.0.2.10' | 账号 app_user 从 192.0.2.10 发起连接被拒绝 |
(using password: YES) | 请求中带了密码,说明不是"空密码"问题,而是账号/密码不匹配,或该来源 IP 无授权 |
| 高频重复 | 说明有程序在持续重试连接(连接池、定时任务、重连机制) |
问题在于:DB 侧只知道来源 IP 是 192.0.2.10,并不知道这是哪台应用、哪个进程、哪个服务在连。 同一台应用服务器上可能跑着多个服务,直接去翻代码或挨个问人不现实。
二、排查思路
整体链路:
MySQL 报错(来源IP)
└─> 登录该 IP 的应用服务器
└─> 按 3306 目标端口查连接,找出异常/滞留连接
└─> 拿到连接对应的 PID
└─> ps -fp PID 定位进程与启动命令
└─> 查看该程序日志,定位根因三、实操过程
Step 1:登录报错来源的应用服务器
ssh 192.0.2.10Step 2:按目标端口 3306 查看所有连接及对应进程
ss -tnp "dport = :3306"输出类似:
State Recv-Q Send-Q Local Address:Port Peer Address:Port Process
ESTAB 0 0 192.0.2.10:51234 198.51.100.20:3306 users:(("java",pid=18872,fd=88))
TIME-WAIT 0 0 192.0.2.10:51240 198.51.100.20:3306
TIME-WAIT 0 0 192.0.2.10:51241 198.51.100.20:3306
CLOSE-WAIT 1 0 192.0.2.10:51255 198.51.100.20:3306 users:(("java",pid=20341,fd=52))重点关注两类连接:
- 大量处于
TIME-WAIT/CLOSE-WAIT/FIN-WAIT状态的连接:典型的"连上就被拒、然后不断重连"的表现,与 DB 端高频Access denied高度吻合。 - 带
users:(("进程名",pid=xxx,...))的 ESTAB/CLOSE-WAIT 连接:能直接拿到进程名和 PID。
小技巧:
ss -tnp默认可能看不到进程信息,普通用户需sudo。- 想看连接定时器(判断是否卡死/超时)可加
-o:ss -tnpo "dport = :3306"。- 只筛异常状态:
ss -tnp state close-wait "( dport = :3306 )"。- 老系统没有
ss时可用:netstat -anp | grep 3306。
Step 3:用 PID 反查进程
从上一步拿到 PID(示例为 18872 / 20341):
ps -fp 18872输出:
UID PID PPID C STIME TTY TIME CMD
appuser 18872 1 0 Oct19 ? 00:12:33 /usr/local/jdk/bin/java -jar /opt/apps/data-sync-service/data-sync-service.jar --spring.profiles.active=prod到这里已经能确认:是 data-sync-service 这个数据同步服务在连数据库。
如果需要进一步确认工作目录、配置文件、环境变量(尤其是数据库账号密码从哪来的):
ls -l /proc/18872/cwd # 进程工作目录
tr '\0' ' ' < /proc/18872/cmdline; echo # 完整启动命令
tr '\0' '\n' < /proc/18872/environ | grep -i -E 'db|mysql|pass' # 环境变量中的配置线索Step 4:查应用日志定位根因
进入应用日志目录(示例):
tail -n 200 /opt/apps/data-sync-service/logs/app.log | grep -i -E 'mysql|access denied|sql'日志中可以看到类似:
ERROR c.z.dynamic.datasource ... Failed to obtain JDBC Connection;
nested exception is java.sql.SQLException:
Access denied for user 'app_user'@'192.0.2.10' (using password: YES)结合 Step 3 看到的启动参数 --spring.profiles.active=prod,检查该环境对应的配置文件:
grep -n -A3 "app_user" /opt/apps/data-sync-service/config/application-prod.yml对比后发现问题:配置文件中该数据源使用的密码与 DB 侧 app_user 账号当前密码不一致(疑似近期改过 DB 密码,但该服务配置文件未同步更新),导致服务启动后反复重连、每次都被 MySQL 拒绝并刷 Access denied 日志。
Step 5:处理与验证
- 修正应用配置中的数据库密码(或按规范走配置中心/密钥管理,避免明文散落)。
- 重启/滚动发布该服务。
- 验证:
# 应用侧:确认无异常滞留连接
ss -tnp "dport = :3306" | grep -E 'CLOSE-WAIT|TIME-WAIT' | wc -l
# DB 侧:确认不再新增 Access denied
tail -f /var/log/messages | grep "Access denied"四、根因小结
- 直接原因:数据同步服务
data-sync-service的数据库配置密码与app_user实际密码不一致。 - 放大因素:连接池/重试机制在密码错误时持续重连,导致 DB 端日志被高频刷屏,且产生大量短连接。
- 表象:DB 端只看到 IP 和高频报错,无法直接定位归属程序。
五、可复用的排查命令清单
| 目的 | 命令 | |
|---|---|---|
| 查本机到 3306 的所有连接及进程 | ss -tnp "dport = :3306" | |
| 只看异常状态连接 | ss -tnp state close-wait "( dport = :3306 )" | |
| 显示连接定时器 | ss -tnpo "dport = :3306" | |
| 老系统替代方案 | `netstat -anp \ | grep 3306` |
| PID 反查进程 | ps -fp <PID> | |
| 进程工作目录 | ls -l /proc/<PID>/cwd | |
| 完整启动命令 | tr '\0' ' ' < /proc/<PID>/cmdline | |
| 进程环境变量 | tr '\0' '\n' < /proc/<PID>/environ | |
| 按端口查进程(lsof) | lsof -i :3306 -n -P |
六、经验与反思
- DB 报错要第一时间关联来源 IP:
Access denied ... @'IP'中的 IP 就是排查入口,登录对应机器反查连接最快。 (using password: YES/NO)是重要线索:YES一般是密码错/无授权;NO才是没传密码(配置缺失)。- 连接状态能说明问题:大量
TIME-WAIT/CLOSE-WAIT+ 高频重连,通常对应"认证失败后不停重试"。 - 密码类配置应集中管理:改 DB 密码时要有清单化通知机制(配置中心、变更单),避免应用配置遗漏。
- 建议加监控:对
/var/log/messages中Access denied做告警(如按来源 IP + 账号聚合计数),能在刷屏前就发现问题;应用侧连接池可配置失败退避重试,降低对 DB 的冲击。
一句话总结:DB 日志告诉你"谁被拒了",ss -tnp + ps -fp 告诉你"是谁在连",应用日志告诉你"为什么连不上"。三跳定位,比盲目翻代码快得多。
脱敏对照(便于对照原文理解):
- 主机名
DB-SERVER-01← 原 DB 主机名- 账号
app_user← 原业务账号- 应用服务器
192.0.2.10← 原来源 IP(RFC 5737 文档地址段)- DB 服务器
198.51.100.20← 原 DB IP- 服务
data-sync-service← 原业务服务名- 路径
/opt/apps/data-sync-service/← 原部署路径