有一臺(tái)預(yù)上線的服務(wù)器最近在做壓力測(cè)試,也引發(fā)了一系列的相關(guān)問題贷洲,排查思路可以提供參考收厨。
問題的起因就是收到同事提醒,根據(jù)監(jiān)控報(bào)警提示优构,磁盤空間滿了诵叁。上面有一個(gè)MySQL服務(wù),現(xiàn)在已經(jīng)寫入不了數(shù)據(jù)了钦椭。
>>create table test(id int);
ERROR14 (HY000): Can't change size of file (Errcode: 28 - No space left on device)
碰到這類問題拧额,直觀的思路就是查看分區(qū)下最大的文件,當(dāng)然如果足夠智能彪腔,也可以啟用前幾天提到的故障自愈的實(shí)現(xiàn)思路侥锦。
當(dāng)我切換到日志目錄的時(shí)候,我發(fā)現(xiàn)慢日志文件竟然有這么大德挣,都是百G級(jí)別恭垦。
-rw-r-----1 mysql mysql302365433856 Nov7 07:55 slowquery.log
當(dāng)時(shí)也是為了盡快的釋放慢日志文件的空間,所以先是選擇了導(dǎo)出部分日志到本地,作為后續(xù)的分析所用番挺,然后清理了這個(gè)日志文件唠帝。
系統(tǒng)層面是清理了文件,空間也可以通過du的方式看到是釋放了玄柏,但是使用df -h的方式卻不奏效襟衰,看起來是文件的句柄沒有正確釋放粪摘,在這種情況下,系統(tǒng)雖然釋放了不少的空間徘意,但是數(shù)據(jù)庫層面還是寫入不了數(shù)據(jù)的苔悦。
這種情況該怎么做,釋放句柄最好的一種方式就是重啟椎咧,但是顯然這不是一個(gè)好的方法间坐,有些簡(jiǎn)單暴力,有沒有更好的方案呢邑退,我們來看看滿日志相關(guān)的參數(shù)竹宋。
>show variables like'%slow%';
+-----------------------------------+------------------------------------+
| Variable_name? ? ? ? ? ? ? ? ? ? | Value? ? ? ? ? ? ? ? ? ? ? ? ? ? ? |
+-----------------------------------+------------------------------------+
| log_slow_admin_statements? ? ? ? | OFF? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? |
| log_slow_filter? ? ? ? ? ? ? ? ? |? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? |
| log_slow_rate_limit? ? ? ? ? ? ? |1 ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?|
| log_slow_rate_type? ? ? ? ? ? ? ? | session? ? ? ? ? ? ? ? ? ? ? ? ? ? |
| log_slow_slave_statements? ? ? ? | OFF? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? |
| log_slow_sp_statements? ? ? ? ? ? | ON? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? |
| log_slow_verbosity? ? ? ? ? ? ? ? |? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? |
| max_slowlog_files? ? ? ? ? ? ? ? |0 ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?|
| max_slowlog_size? ? ? ? ? ? ? ? ? |0 ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?|
| slow_launch_time? ? ? ? ? ? ? ? ? |2 ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?|
| slow_query_log? ? ? ? ? ? ? ? ? ? | OFF? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? |
| slow_query_log_always_write_time? |10.000000 ? ? ? ? ? ? ? ? ? ? ? ? ?|
| slow_query_log_file? ? ? ? ? ? ? | /data/mysql_4350/log/slowquery.log |
| slow_query_log_use_global_control |? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? |
+-----------------------------------+------------------------------------+
這里我們可用的一個(gè)直接方式就是先關(guān)閉滿日志,達(dá)到釋放句柄的目的地技,然后再次重啟開啟蜈七。
想明白了,操作就很簡(jiǎn)單了莫矗。
>set global slow_query_log=off;
Query OK, 0 rows affected (6.54 sec)
>set global slow_query_log=on;
Query OK, 0 rows affected (0.00 sec)
很明顯飒硅,磁盤空間釋放了不少,對(duì)于慢日志的問題分析作谚,其中里面有一個(gè)數(shù)據(jù)字典表存在大量的查詢請(qǐng)求三娩,添加了索引之后,該問題得到了有效控制妹懒。
# df -h
Filesystem? ? ? ? ? ? Size? Used Avail Use% Mounted on
/dev/sda325G5.5G18G24% /
tmpfs31G12K31G1% /dev/shm
/dev/sda1190M78M103M44% /boot
/dev/mapper/data-main
717G400G281G59% /data
這個(gè)問題剛過一會(huì)雀监,又收到報(bào)警說磁盤空間又滿了,這次排除了慢日志的影響眨唬,發(fā)現(xiàn)是審計(jì)日志出了問題会前。
$ df -h
Filesystem? ? ? ? ? ? Size? Used Avail Use% Mounted on
/dev/sda325G5.5G18G24% /
tmpfs31G12K31G1% /dev/shm
/dev/sda1190M78M103M44% /boot
/dev/mapper/data-main
717G609G72G90% /data
這里需要說明的是,審計(jì)插件有幾類比較流行的匾竿,這里用到的是Percona audit plugin,其實(shí)從性價(jià)比來說瓦宜,這個(gè)插件的控制粒度還算比較粗,如果從控制的粒度來說岭妖,MariaDB Audit plugin要好很多临庇,推薦使用反璃。
審計(jì)日志有差不多600G,在這種高壓測(cè)試之下,量級(jí)還是很大的假夺,為了緩解問題版扩,也是刪除了600G的審計(jì)日志文件。
打開審計(jì)日志的參數(shù)選項(xiàng):
>show variables like'%audit%';
+-----------------------------+---------------+
| Variable_name? ? ? ? ? ? ? | Value? ? ? ? |
+-----------------------------+---------------+
| audit_log_buffer_size? ? ? |1048576 ? ? ? |
| audit_log_exclude_accounts? |? ? ? ? ? ? ? |
| audit_log_exclude_commands? |? ? ? ? ? ? ? |
| audit_log_exclude_databases |? ? ? ? ? ? ? |
| audit_log_file? ? ? ? ? ? ? | audit.log? ? |
| audit_log_flush? ? ? ? ? ? | OFF? ? ? ? ? |
| audit_log_format? ? ? ? ? ? | OLD? ? ? ? ? |
| audit_log_handler? ? ? ? ? | FILE? ? ? ? ? |
| audit_log_include_accounts? |? ? ? ? ? ? ? |
| audit_log_include_commands? |? ? ? ? ? ? ? |
| audit_log_include_databases |? ? ? ? ? ? ? |
| audit_log_policy? ? ? ? ? ? | ALL? ? ? ? ? |
| audit_log_rotate_on_size? ? |0 ? ? ? ? ? ? |
| audit_log_rotations? ? ? ? |0 ? ? ? ? ? ? |
| audit_log_strategy? ? ? ? ? | ASYNCHRONOUS? |
| audit_log_syslog_facility? | LOG_USER? ? ? |
| audit_log_syslog_ident? ? ? | percona-audit |
| audit_log_syslog_priority? | LOG_INFO? ? ? |
+-----------------------------+---------------+
18 rowsin set (0.01 sec)
這里可以選的方式是修改審計(jì)日志的策略侄泽,比如我們從ALL修改為NONE,但是這種方式還是有些局限,因?yàn)闆]有生效蜻韭。到了這個(gè)時(shí)候可供選擇的方案就很少了悼尾,如果要釋放句柄,我們可以簡(jiǎn)單先看看肖方,比如通過lsof來查看未釋放的句柄闺魏。
# lsof|grep delete
mysqld3218 ?mysql5u? REG253,0 ?26946 ? 85458954 /data/mysql_4350/tmp/ib6i5l8w (deleted)
mysqld3218 ?mysql6u? REG253,0 ?0 ? 85458955 /data/mysql_4350/tmp/ibzgbLJz (deleted)
mysqld3218 ?mysql7u? REG253,0 ?0 ? 85458956 /data/mysql_4350/tmp/ibUZDalC (deleted)
mysqld3218 ?mysql8u? REG253,0 ?0 ? 85458960 /data/mysql_4350/tmp/ibhdSF1K (deleted)
mysqld3218 ?mysql12u? REG253,0 ?0 ? 85458961 /data/mysql_4350/tmp/ibo46oDR (deleted)
mysqld3218 ?mysql41w? REG253,0 635612876075 ?85460307 /data/mysql_4350/data/audit.log (deleted)
但是很明顯這個(gè)進(jìn)程就是MySQL服務(wù)的進(jìn)程號(hào),直接kill MySQL實(shí)在是太暴力了俯画,而且這個(gè)測(cè)試還在進(jìn)行中艰垂,為了避免不必要的解釋和麻煩,我們也是不能重啟數(shù)據(jù)庫的猜憎。
# ps -ef|grep 3218
mysql3218 ? 2015 22 Oct31 ?1-14:53:02 /usr/local/mysql/bin/mysqld --basedir=/usr/local/mysql --datadir=/data/mysql_4350/data --plugin-dir=/usr/local/mysql/lib/mysql/plugin --user=mysql --log-error=/data/mysql_4350/log/mysql.err --open-files-limit=16384 --pid-file=/data/mysql_4350/tmp/mysql.pid --socket=/data/mysql_4350/tmp/mysql.sock --port=4350
root87186 ?86999 ?0 15:20 pts/0 ? ?00:00:00 grep3218
這里有一個(gè)參數(shù)引起了我的注意胰柑,那就是audit_log_flush柬讨,有點(diǎn)類似于MySQL里面的flush logs的方式。通過觸發(fā)這個(gè)參數(shù)就可以釋放已有的句柄了踩官。
>set global audit_log_flush=on;
Query OK, 0 rows affected (10.04 sec)
通過幾輪問題分析和排查蔗牡,日志類的問題總算得到了基本解決。
后續(xù)需要改進(jìn)的就是對(duì)于審計(jì)日志的管理蛋逾,目前做壓力測(cè)試其實(shí)是可以關(guān)閉這一類的審計(jì)的区匣。
而對(duì)于慢日志的分析也是重中之重蒋院,如果在極高的壓力下欺旧,差不多1~2分鐘會(huì)產(chǎn)生1G的慢日志蛤签,按照并發(fā)來看,這個(gè)值是很高的称龙。所以在基本穩(wěn)定了性能之后鲫尊,慢日志的量級(jí)有了明顯的變化沦偎。