記一次FreeBSD系統中mysql服務異常的排查過程

myskies發表於2022-07-13

隨著監控助理突然提示很多資料庫連線錯誤:

image.png

排查資料庫錯誤便隨之提上了日程。

重啟大法

不得不說,有時候重啟大法還是挺好使的。所以我們上來也嘗試重啟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在啟動的時候並沒有自動刪除歷史的日誌,可能還需要在某個時間節點上觸發吧,待後續進行追蹤。

相關文章