MySQL 8.0 故障排查实战 — 连接频繁断开/重连

原创三石 All China Database Union 1天前

132

Part1故障现象

业务反馈：无论是应用程序还是 DBeaver 连接数据库，第一次执行SQL正常，但很快（1秒以内）再次执行SQL就会报错需要重新连接，无法连续执行SQL。这样根本无法保证业务正常运行，希望我能解决一下。

DBeaver 报错：

datasource was invalidated
live connection count: 3/3

应用报错：

com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure
The last packet successfully received from the server was 5,263 milliseconds ago.
The last packet sent successfully to the server was 5,264 milliseconds ago.

Part2排查流程

2.1检查连接超时参数（正常）

mysql> show global variables like '%timeout';
+-----------------------------------+----------+
| Variable_name                     | Value    |
+-----------------------------------+----------+
| connect_timeout                   | 10       |
| interactive_timeout               | 28800    |
| wait_timeout                      | 28800    |
+-----------------------------------+----------+

connect_timeout是建立连接的允许时长
wait_timeout连接建立后的空闲阶段（非交互式连接-应用程序）
interactive_timeout连接建立后的空闲阶段（交互式连接-命令行工具）

set global connect_timeout=10;
set global interactive_timeout=28800;
set global wait_timeout=28800;

show global variables like '%timeout';
+-----------------------------------+----------+
| Variable_name                     | Value    |
+-----------------------------------+----------+
| connect_timeout                   | 10       |
| interactive_timeout               | 28800    |
| wait_timeout                      | 28800    |
+-----------------------------------+----------+

三个参数都在正常范围，重置后问题依旧。→排除参数问题

2.2检查 DNS 反向解析（已关闭）

业务那边发了一段Ai的回答，我觉得这段很有用

#修改建立连接时长为30秒
set global connect_timeout=30;

mysql> show global variables like 'skip_name_resolve';
+-------------------+-------+
| Variable_name     | Value |
+-------------------+-------+
| skip_name_resolve | ON    |
+-------------------+-------+
如果这个是OFF，又不方便重启数据库的话，可以注释DNS

vim /etc/resolv.conf
将里边的内容都添加#注释

加大连接时长，已经是 ON 状态，而且注释DNS。联系业务重连数据库，问题依旧。→排除 DNS 解析问题

2.3查看 MySQL error log —— 发现关键线索

查看数据库持续报警的信息

2026-06-16T11:29:30.187881Z 0 [Warning] [MY-011825] [InnoDB] Cannot add field `` in table ``.`` because after adding it, the row size is 8287 which is greater than maximum allowed size (8126) for a record on index leaf page.
2026-06-16T11:29:30.190291Z 0 [Warning] [MY-011825] [InnoDB] Cannot add field `` in table ``.`` because after adding it, the row size is 8807 which is greater than maximum allowed size (8126) for a record on index leaf page.
2026-06-16T11:29:30.194369Z 0 [Warning] [MY-011825] [InnoDB] Cannot add field `str8` in table ``.`` because after adding it, the row size is 8499 which is greater than maximum allowed size (8126) for a record on index leaf page.
2026-06-16T11:30:56.780472Z mysqld_safe Logging to '/app/mysql/logs/error.log'.
2026-06-16T11:30:56.831494Z mysqld_safe Starting mysqld daemon with databases from /app/mysql/data
2026-06-16T11:30:57.130676Z 0 [Warning] [MY-011068] [Server] The syntax '--ssl=off' is deprecated and will be removed in a future release. Please use --tls-version='' instead.
2026-06-16T11:30:57.130846Z 0 [Warning] [MY-010918] [Server] 'default_authentication_plugin' is deprecated and will be removed in a future release. Please use authentication_policy instead.
2026-06-16T11:30:57.130875Z 0 [System] [MY-010116] [Server] /app/mysql/bin/mysqld (mysqld 8.0.43) starting as process 4121186
2026-06-16T11:30:57.144840Z 0 [Warning] [MY-013907] [InnoDB] Deprecated configuration parameters innodb_log_file_size and/or innodb_log_files_in_group have been used to compute innodb_redo_log_capacity=4294967296. Please use innodb_redo_log_capacity instead.
2026-06-16T11:30:57.147396Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2026-06-16T11:30:59.270077Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2026-06-16T11:30:59.700175Z 0 [System] [MY-010229] [Server] Starting XA crash recovery...
2026-06-16T11:30:59.708202Z 0 [System] [MY-010232] [Server] XA crash recovery finished.
2026-06-16T11:30:59.787958Z 0 [Warning] [MY-011302] [Server] Plugin mysqlx reported: 'Failed at SSL configuration: "SSL context is not usable without certificate and private key"'
2026-06-16T11:30:59.788187Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /tmp/mysqlx.sock
2026-06-16T11:30:59.788340Z 0 [System] [MY-010931] [Server] /app/mysql/bin/mysqld: ready for connections. Version: '8.0.43'  socket: '/tmp/mysql.sock'  port: 3306  MySQL Community Server - GPL.

往上翻查到binlog满了

2026-06-15T10:46:24.109981Z 9313 [ERROR] [MY-010839] [Server] MYSQL_BIN_LOG::purge_logs was called with file ./mysql-bin.010 not listed in the index.
2026-06-15T10:46:44.748307Z 9313 [ERROR] [MY-010839] [Server] MYSQL_BIN_LOG::purge_logs was called with file ./mysql-bin.010 not listed in the index.
2026-06-15T10:50:46.467647Z 9302 [ERROR] [MY-000035] [Server] Disk is full writing './binlog.000020' (OS errno 28 - No space left on device). Waiting for someone to free space... Retry in 60 secs. Message reprinted in 600 secs.
2026-06-15T11:00:46.528062Z 9302 [ERROR] [MY-000035] [Server] Disk is full writing './binlog.000020' (OS errno 28 - No space left on device). Waiting for someone to free space... Retry in 60 secs. Message reprinted in 600 secs.
2026-06-15T11:10:46.594428Z 9302 [ERROR] [MY-000035] [Server] Disk is full writing './binlog.000020' (OS errno 28 - No space left on device). Waiting for someone to free space... Retry in 60 secs. Message reprinted in 600 secs.
2026-06-15T11:20:46.649184Z 9302 [ERROR] [MY-000035] [Server] Disk is full writing './binlog.000020' (OS errno 28 - No space left on device). Waiting for someone to free space... Retry in 60 secs. Message reprinted in 600 secs.
2026-06-15T11:30:46.705848Z 9302 [ERROR] [MY-000035] [Server] Disk is full writing './binlog.000020' (OS errno 28 - No space left on device). Waiting for someone to free space... Retry in 60 secs. Message reprinted in 600 secs.
2026-06-15T11:40:46.768885Z 9302 [ERROR] [MY-000035] [Server] Disk is full writing './binlog.000020' (OS errno 28 - No space left on devic2026-06-16T01:35:07.419589Z 9302 [ERROR] [MY-011072] [Server] Binary logging not possible. Message: An error occurred during flush stage of the commit. 'binlog_error_action' is set to 'ABORT_SERVER'. Server is being stopped..
2026-06-16T01:35:07Z UTC - mysqld got signal 6 ;

发现1：数据库在持续异常重启，但没有明确的 crash 原因，最早开始时间2026-06-16T09:35:08.388741Z

发现2： 6月15日 18：46 ，binlog自动清理失败（purge_logs找不到索引中的文件），根目录（binlog所在路径）磁盘写满，导致 binlog 无法写入，引起数据库宕机

发现3： error log 时间比实际时间慢了8个小时（log_timestamps=UTC），可以记录并优化

2.4查看系统日志 —— 找到根因

[root@~]# tail -3000f /var/log/messages

Jun 16 09:36:06 CNSZULCROAP01 qualys-mux[3634145]: Failed to open config file.
Jun 16 09:36:06 CNSZULCROAP01 qualys-mux[3634145]: Error: The qualys-mux binary could not Initialize.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: State 'stop-sigterm' timed out. Killing.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 1841 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 1147 (mysqld_safe) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632609 (mysqld) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632619 (ib_io_ibuf) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632622 (ib_io_rd-3) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632623 (ib_io_rd-4) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632624 (ib_io_wr-1) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632625 (ib_io_wr-2) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632626 (ib_io_wr-3) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632627 (ib_io_wr-4) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632628 (ib_pg_flush_co) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632630 (ib_pg_flush-2) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632631 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632645 (ib_log_checkpt) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632646 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632647 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632648 (ib_log_wr_notif) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632649 (ib_log_writer) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632650 (ib_log_files_g) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632750 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632751 (ib_srv_err_mon) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632752 (ib_srv_mon) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632775 (ib_buf_resize) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632776 (ib_src_main) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632777 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632778 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632779 (xpl_worker-1) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632780 (xpl_worker-2) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632801 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632802 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632803 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632804 (ib_srv_wkr-1) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632805 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632806 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632960 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632961 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632965 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632966 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3632967 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3633244 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 3633245 (connection) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Killing process 1841 (n/a) with signal SIGKILL.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Failed with result 'timeout'.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: Stopped MySQL Server.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: Consumed 2h 17min 27.587s CPU time, 4.4G memory peak.

🔑关键发现：systemd 在持续 kill MySQL 进程，原因是stop-sigterm超时。

这里有个同事提出，可能说MySQL的配置有问题，我们无法从mysql的报警日志和服务器的系统日志来判断，只能看看mysql的配置文件了，但是这里我和业务沟通他们是怎么启动数据库的，他们说是使用了systemctl的方式，所以我觉得先看看这个

2.5检查 systemd 配置 —— 罪魁祸首

发现关键配置问题：

因为不知道他的配置命令，所以尝试使用 
systemctl edit mysql
 

### Lines below this comment will be discarded
 
### See /etc/systemd/system/mysql.service
 
#[Unit]
#Description=MySQL Server
#After=network.target
#After=syslog.target
# 
#[Service]
#PIDFile=/mysql/data/mysql.pid
## 请修改: 指向你MySQL安装目录下的mysqld可执行文件
#ExecStart=/app/mysql/support-files/mysql.server start
#ExecStop=/app/mysql/support-files/mysql.server stop
## 请修改: 设置运行MySQL的用户和用户组 (通常为 mysql)
#User=mysql
#Group=mysql
## 可选: 如果MySQL进程被意外终止，尝试自动重启
#Restart=on-failure
## 可选: 设置打开文件的限制
#LimitNOFILE=infinity
#PermissionsStartOnly=true
#RestartPreventExitStatus=1
#PrivateTmp=false
# 
#[Install]
#WantedBy=multi-user.target

百度以后添加这个参数，使用systemctl重启数据库进程结果还是持续异常重启

# TimeoutStopSec=600          ← 停止超时设置过长

捋一下思路

发现1：/etc/systemd/system/mysql.service.d/.#override.conf，这个代表打开以后，没有正常关闭，是个隐患

发现2：配置文件的每行参数前边都有#注释，也就是说参数还没生效，这就是从别的地方复制粘贴搞过来的，都没自己看

发现3：PIDFile=/mysql/data/mysql.pid这行参数路径还不对，应该是/app 不是 /mysql

发现4：#Restart=on-failure异常退出然后重启，也许这个是默认参数？还是有别的参数文件在生效？

2.6根因

有人在服务器上直接 rm 删了 binlog 文件，但这操作有个问题——MySQL 的 binlog 索引文件（.index）没有同步更新。

索引里还记着那些已经被删掉的文件名，导致 MySQL 自己的自动清理机制找不到文件，清理失败。binlog 继续产生，磁盘一点点被打满，最后 MySQL 写不进去就挂了。

2.7反复崩溃重启原因

有人在 OS 层用 rm 删除了 binlog 文件
    ↓
但未同步清理 mysql-bin.index 索引文件
    ↓
MySQL 自动清理机制找不到文件 → PURGE BINARY LOGS 失败
    ↓
binlog 持续产生 → 根目录磁盘写满
    ↓
MySQL 无法写入 → 崩溃（signal 6 / ABORT_SERVER）
    ↓
systemd 配置了 Restart=on-failure → 自动拉起
    ↓
拉起后做 crash recovery，磁盘满导致恢复极慢
    ↓
TimeoutStopSec 很短（约 30s）→ 优雅关闭超时 → systemd SIGKILL 强杀
    ↓
Restart=on-failure → 再次拉起 → 再次超时强杀 → 死循环

这就是"第一次能连、很快又断开"的根本原因：MySQL 一直处于 crash recovery 状态，实例未完全就绪，连接进来后很快又挂掉。

这里提两点，一个是为什么预估是30秒的默认事件

Jun 16 09:36:06 CNSZULCROAP01 qualys-mux[3634145]: Error: The qualys-mux binary could not Initialize.
Jun 16 09:36:38 CNSZULCROAP01 systemd[1]: mysql.service: State 'stop-sigterm' timed out. Killing.

可以看到两行信息之间的报错时间之间间隔了32秒，所以预估是32秒，而且也可以通过命令systemctl show mysql --property=TimeoutStopUSec来查看

Part3解决方案

3.1临时恢复（立即生效）

停止 systemd 管理的 MySQL，改用mysqld_safe启动：

# 停止 systemd 管理的 MySQL
systemctl stop mysqld
 
# 确认进程已停止
ps -ef | grep mysql
 
# 使用 mysqld_safe 手动启动（跳过 systemd 的超时控制），这个是我找的临时语句，需要和具体环境一样
mysqld_safe --defaults-file=/mysql/conf/my3306.cnf --user=mysql &

3.2验证方法

# 1. 查看系统日志是否还在强制杀 MySQL 进程
tail -f /var/log/messages | grep mysql
 
# 2. 检查进程稳定性和运行时长
ps -ef | grep mysql
 
# 3. 查看 error log 是否还在反复重启
tail -f /app/mysql/logs/error.log
 
# 4. 使用 DBeaver 或应用测试连续查询

3.3长期修复（根治方案）

# 方案A：修改 systemd 配置，移除 Restart=on-failure，或增加合理限制
/etc/systemd/system/mysql.service
[Service]
Restart=no
# 或
Restart=on-failure
RestartSec=30
StartLimitInterval=600
StartLimitBurst=3
 
# 方案B：解决根目录磁盘空间问题
# 1. 清理 binlog（确认业务不需要后）
删除所有
PURGE BINARY LOGS BEFORE NOW();
删除三天前
PURGE BINARY LOGS BEFORE NOW() - INTERVAL 3 DAY;
 
# 2. 将 binlog 迁移到有空间的目录
# 在 my.cnf 中修改 log-bin 路径
 
# 3. 设置 binlog 过期时间
SET GLOBAL expire_logs_days = 7;
# 或 MySQL 8.0 使用
SET GLOBAL binlog_expire_logs_seconds = 604800;

Part4排查方法论总结

业务反馈异常
    ↓
检查连接超时参数（正常）
    ↓
检查 DNS 反向解析（正常）
    ↓
查看 MySQL error log  ← 关键！
    ↓
查看系统日志 /var/log/messages  ← 关键！
    ↓
检查 systemd 配置  ← 根因！
    ↓
临时修复：mysqld_safe 启动
长期修复：修改 systemd 配置 + 磁盘空间治理

Part5排查心得

1、错误日志时间偏差处理： error log 默认使用 UTC 时间，比北京时间慢8小时。对比时间时先做换算或设置为 log_timestamps = system

2、连接异常 ≠ 连接参数问题：当连接参数正常时，故障可能在 OS 层面（systemd/磁盘/OOM）

3、systemd 自动重启 ≠ 高可用： Restart=on-failure 在进程反复 crash 时会导致循环重启，反而加剧问题

4、从现象反推根因： "第一次能连、第二次断" → 表明进程死了又被拉起 → 看系统日志谁在杀进程

墨力计划 mysql

「喜欢这篇文章，您的关注和赞赏是给作者最好的鼓励」

关注作者