记一次FreeBSD系统中mysql服务异常的排查过程

随着监控助理突然提示很多数据库连接错误：

排查数据库错误便随之提上了日程。

重启大法

不得不说，有时候重启大法还是挺好使的。所以我们上来也尝试重启mysql

$ /usr/local/etc/rc.d/mysql-server stop
$ /usr/local/etc/rc.d/mysql-server start

再次连接，数据数据直接就连不上了。此时便需要来到正确的轨迹上：看报错内容，根据报错内容来排查原因，解决问题。

错误日志

很遗憾的是，mysql在启动过程中，即使启动失败，也不会报什么的错误信息。我们查看mysql是否成功启动则需要使用mysql-server status命令：

root@YunzhiTest:/usr/home/panjie # /usr/local/etc/rc.d/mysql-server status
mysql is not running.

而是否打印日志，以及日志的位置放在哪，则需要我们进行手动配置。在mysql服务成功启动的前提下，我们其实是可以使用mysql的相关命令来查看当前的配置文件位置的，无奈当前mysql并没有成功启动，所以此时则需要借助一些查询软件或是当初安装mysql使用的工具（比如FreeBSD的ports)来查找mysql的配置文件位置了。在FreeBSD中，mysql的配置文件位于/usr/local/etc/mysql中：

root@YunzhiTest:/usr/home/panjie # cd /usr/local/etc/mysql/
root@YunzhiTest:/usr/local/etc/mysql # ls
keyring        my.cnf        my.cnf.sample

然后我们备份一个配置文件cp my.cnf my.cnf.bak后再对其进行编辑：

[mysqld]
log-error                       = /var/log/mysql/error.log
user                            = mysql
port                            = 3306

在 mysqld 下增加log-error。同时由于当前mysql启动的用户是mysql，还需要保证mysql用户对相关日志路径拥有绝对权限：

$ mdkir /usr/log/mysql
$ chown mysql:mysql /usr/log/mysql

查看日志

此时我们再次启动mysql 服务，则可以查看在/var/log/mysql/下生成的error.log文件了：

$ /usr/local/etc/rc.d/mysql-server start

其比较重要的错误信息如下：

2022-07-11T14:22:25.946391Z 0 [Note] InnoDB: Rollback of non-prepared transactions completed
2022-07-11T14:22:25.946435Z 0 [Note] InnoDB: Setting file '/var/db/mysql/ibtmp1' size to 128 MB. Physically writing the file full; Please wait ...
2022-07-11T14:22:25.947132Z 0 [Note] InnoDB: Progress in MB:
 1002022-07-11T14:22:26.085805Z 0 [Warning] InnoDB: Retry attempts for writing partial data failed.
2022-07-11T14:22:26.085855Z 0 [ERROR] InnoDB: Write to file /var/db/mysql/ibtmp1failed at offset 133169152, 1048576 bytes should have been written, only 0 were written. Operating system error number 28. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
2022-07-11T14:22:26.085940Z 0 [ERROR] InnoDB: Error number 28 means 'No space left on device'
2022-07-11T14:22:26.085951Z 0 [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html
2022-07-11T14:22:26.085968Z 0 [ERROR] InnoDB: Could not set the file size of '/var/db/mysql/ibtmp1'. Probably out of disk space

上述错误大概就是在说一个问题：磁盘空间满了，此问题导致mysql无法启动。

整理数据

问题的根本原因找到了，解决问题便成了最轻松的事情。

root@YunzhiTest:/usr/local/etc/mysql # df -h
Filesystem                     Size    Used   Avail Capacity  Mounted on
/dev/ufsid/59a7effe7885633c     39G     36G    124M   100%    /
devfs                          1.0K    1.0K      0B   100%    /dev
zroot/mengyunzhi                48G     40G    8.4G    82%    /mengyunzhi
zroot                          8.4G     23K    8.4G     0%    /zroot

首先我们查看my.cnf中的数据库文件配置路径:

datadir                         = /var/db/mysql
tmpdir                          = /var/db/mysql_tmpdir
slave-load-tmpdir               = /var/db/mysql_tmpdir
secure-file-priv                = /var/db/mysql_secure

然后依次查看其占用空间：

root@YunzhiTest:/var/db # du -h -d 1
180M    ./portsnap
3.1M    ./etcupdate
8.0K    ./zfsd
 36K    ./entropy
4.0K    ./ipf
4.0K    ./hyperv
 87M    ./pkg
688K    ./ports
1.5G    ./freebsd-update
 12K    ./ntp
148K    ./fontconfig
8.0K    ./sudo
 18G    ./mysql
4.0K    ./mysql_secure
4.0K    ./mysql_tmpdir
8.0K    ./redis
8.0K    ./colord
 20G    .

发现mysql占用了18G，但实际上并没有这么多数据。进入mysql文件夹后继续查看：

root@YunzhiTest:/var/db/mysql # du -ah | sort -h
104M    ./log/log.ibd
105M    ./log
130M    ./mysql/slow_log.CSV
131M    ./mysql-bin.000108
136M    ./measurement/instrument.ibd
142M    ./mysql-bin.000113
145M    ./mysql-bin.000104
150M    ./mysql
190M    ./mysql-bin.000114
214M    ./mysql-bin.000111
224M    ./mysql-bin.000109
230M    ./mysql-bin.000103
256M    ./ib_logfile0
256M    ./ib_logfile1
256M    ./mysql-bin.000106
274M    ./mysql-bin.000107
287M    ./mysql-bin.000110
344M    ./mysql-bin.000102
346M    ./instrument
380M    ./mysql-bin.000112
404M    ./measurement/instrument_check_info_mandatory_instrument_check_ability_list.ibd
502M    ./mysql-bin.000120
658M    ./mysql-bin.000121
678M    ./mysql-bin.000125
786M    ./mysql-bin.000116
813M    ./mysql-bin.000123
900M    ./mysql-bin.000118
1.0G    ./measurement
1.0G    ./mysql-bin.000115
1.0G    ./mysql-bin.000117
1.0G    ./mysql-bin.000119
1.0G    ./mysql-bin.000122
1.0G    ./mysql-bin.000124
1.2G    ./switchgear1
1.2G    ./switchgear1/record_value.ibd
2.3G    ./ibdata1

最终发现空间大户如上，我们发现系统中的.mysql-bin文件占据了较大的空间，而mysql-bin文件大体有两个作用：1是用来进行数据恢复；2是在主从数据库的时保障高可用性。

虽然可以删除相应的mysql-bin文件，但是保留该文档还是有一定的必要性的。但我们可以将其保留的日期缩短一些，比如我们只保留一周的。查看文件的生成日期：

root@YunzhiTest:/var/db/mysql # ls -alh
-rw-r-----   1 mysql  mysql   344M Jun 13 17:02 mysql-bin.000102
-rw-r-----   1 mysql  mysql   229M Jun 14 13:53 mysql-bin.000103
-rw-r-----   1 mysql  mysql   145M Jun 14 20:44 mysql-bin.000104
-rw-r-----   1 mysql  mysql    56M Jun 15 00:11 mysql-bin.000105
-rw-r-----   1 mysql  mysql   256M Jun 15 22:34 mysql-bin.000106
-rw-r-----   1 mysql  mysql   274M Jun 16 11:29 mysql-bin.000107
-rw-r-----   1 mysql  mysql   131M Jun 16 17:38 mysql-bin.000108
-rw-r-----   1 mysql  mysql   224M Jun 17 04:00 mysql-bin.000109
-rw-r-----   1 mysql  mysql   287M Jun 17 17:26 mysql-bin.000110
-rw-r-----   1 mysql  mysql   214M Jun 18 03:29 mysql-bin.000111
-rw-r-----   1 mysql  mysql   380M Jun 18 21:19 mysql-bin.000112
-rw-r-----   1 mysql  mysql   142M Jun 20 17:02 mysql-bin.000113
-rw-r-----   1 mysql  mysql   189M Jun 21 00:09 mysql-bin.000114
-rw-r-----   1 mysql  mysql   1.0G Jun 22 19:35 mysql-bin.000115
-rw-r-----   1 mysql  mysql   785M Jun 24 00:16 mysql-bin.000116
-rw-r-----   1 mysql  mysql   1.0G Jun 25 19:06 mysql-bin.000117
-rw-r-----   1 mysql  mysql   900M Jun 27 08:14 mysql-bin.000118
-rw-r-----   1 mysql  mysql   1.0G Jun 29 11:30 mysql-bin.000119
-rw-r-----   1 mysql  mysql   502M Jul  1 13:09 mysql-bin.000120
-rw-r-----   1 mysql  mysql   657M Jul  5 01:38 mysql-bin.000121
-rw-r-----   1 mysql  mysql   1.0G Jul  6 21:05 mysql-bin.000122
-rw-r-----   1 mysql  mysql   813M Jul  8 09:05 mysql-bin.000123
-rw-r-----   1 mysql  mysql   1.0G Jul 10 10:36 mysql-bin.000124
-rw-r-----   1 mysql  mysql   677M Jul 11 21:28 mysql-bin.000125

发现该文件当前保存了近1个月，此时我们先删除两个稍大的历史文件，把空间释放一些出来，然后再去修改一下my.cnf中的保留日期将其缩短为10天。

root@YunzhiTest:/var/db/mysql # rm mysql-bin.000115
root@YunzhiTest:/var/db/mysql # rm mysql-bin.000124
root@YunzhiTest:/var/db/mysql # df -h
Filesystem                     Size    Used   Avail Capacity  Mounted on
/dev/ufsid/59a7effe7885633c     39G     34G    2.1G    94%    /
devfs                          1.0K    1.0K      0B   100%    /dev
zroot/mengyunzhi                48G     40G    8.4G    82%    /mengyunzhi
zroot                          8.4G     23K    8.4G     0%    /zroot

将bin文件的保留天数据设置为10：

binlog_cache_size               = 16M
expire_logs_days                = 10

最后尝试启动mysql

root@YunzhiTest:/usr/local/etc/mysql # /usr/local/etc/rc.d/mysql-server start
Starting mysql.
root@YunzhiTest:/var/log/mysql # /usr/local/etc/rc.d/mysql-server status
mysql is running as pid 11633.

其实除此方法外，如果你的第二硬盘空间够用，还可以直接把mysql的数据文件迁移到第二块硬盘上，我只所以没有这么做是由于我第二块硬盘的剩余空间也仅有8.4G，而这个值小于当前mysql的占用空间18G。所以即便是我想进行迁移，也迁移不过去。其根本原因是由于当下有个系统需要上传大量的较大的文件，而我并没有使用存储来处理这些文件，是时候使用存储来专门存放资源文件了。

追踪：虽然将expire_logs_days的值设置成了10，但mysql在启动的时候并没有自动删除历史的日志，可能还需要在某个时间节点上触发吧，待后续进行追踪。