近期,于一次预上线服务器所进行的压力测试进程里,我们碰到了因磁盘空间已满致使的MySQL服务写入方面的故障。
在运维场景里,这类问题具备典型性,借着这个契机,本文要深入去复盘整个排查过程进而解决问题,还要提炼出针对数据库日志管理以及空间释放还有性能优化的系统性思路。
故障初现:慢查询日志引发的空间危机
监控报警显示磁盘空间耗尽,MySQL实例无法写入。
按照常规思路,首要任务是定位大文件。
>>create table test(id int); ERROR 14 (HY000): Can't change size of file (Errcode: 28 - No space left on device)
转移至日志目录那儿之后,察觉到,慢查询日志这个文件,其体积大得惊人,已然达到了百G的级别。
这直接反映出在高压测试下,数据库中存在大量未优化的查询。
紧急措施是切割并清理该日志文件。
在这个地方,得着重讲一个有关数据库运维的关键要点部位细节情况,运用rm这么个命令,从系统的层面范畴范围以内去把文件给摘除移除掉之后,借助du命令去瞅查看瞧审视一番,磁盘空间确实已然已经是被释放放开了,然而可是但凡是df -h所展示显示呈现出来的空间占用比率却一点都没有变动,仍然是维持原样纹丝不动。
-rw-r----- 1 mysql mysql 302365433856 Nov 7 07:55 slowquery.log
这是由于,MySQL进程依旧持有已删除 文件 所给的句柄,造成内核没办法真正去回收空间,以至于数据库依旧呈不可写 这种状态。
技术深潜:如何在不重启的情况下释放文件句柄
让MySQL服务重新启动,是最径直的解决手段,然而,于高负荷测试或者生产环境里,这可不是最为出色的抉择。
那么,如何优雅地释放句柄?
对于MySQL的慢查询日志,我们可以利用系统变量动态调整。
操作思路如下:
临时将慢日志予以关闭 ,于MySQL客户端执行这样的操作 ,即执行代码 SET GLOBAL slow_query_log = OFF;。
>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 | | +-----------------------------------+------------------------------------+
此操作会促使MySQL关闭当前的日志文件句柄。
2. 再度将慢日志予以开启:去执行 SET GLOBAL slow_query_log = ON;这个操作。
在配置了文件名规则的情形下,MySQL会去重新创建一个全新的日志文件,或者会去重新打开原来有的文件路径。
经由这般样式,文件句柄获成功重置,系统空间获全然释放,数据库回复写入能力。
接着,我们针对备份的慢日志展开分析,发觉某个核心数据字典表存有大量的全表扫描查询。
>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)
把合适的索引创建出来,针对该表高频查询的字段,之后,慢查询量级实现了有效控制。
二次告警:审计日志的空间黑洞
空间问题看似解决,但不久后磁盘再次告急。
# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/sda3 25G 5.5G 18G 24% /
tmpfs 31G 12K 31G 1% /dev/shm
/dev/sda1 190M 78M 103M 44% /boot
/dev/mapper/data-main
717G 400G 281G 59% /data
这次排除慢日志,矛头指向了审计日志(Audit Log)。

在压力测试期间,我们加以运用的audit插件,生成了将近600GB的日志,该日志粒度较为粗大,记录了数量众多的审计事件。
面对新的空间危机,我们再次选择了清理文件。
但关键在于如何彻底释放空间。
$ df -h
Filesystem Size Used Avail Use% Mounted on
/dev/sda3 25G 5.5G 18G 24% /
tmpfs 31G 12K 31G 1% /dev/shm
/dev/sda1 190M 78M 103M 44% /boot
/dev/mapper/data-main
717G 609G 72G 90% /data
直接删除文件后,我们面临同样的句柄未释放问题。
运维技巧:利用参数动态释放审计日志句柄
针对审计日志的句柄释放,有以下几种策略:
强相关标签所指的策略变动,试着把那种针对所有请求全做记录的审计策略,像ALL这种情况,转变更改为不做任何记录的策略,也就是NONE这种策略设定。
但这种方案有时无法实时生效,对已打开的句柄无效。
那种借助 lsof | grep deleted 来进行查看的暴力手段,能够发现,MySQL进程居然依旧持有被删文件的句柄。
直接kill MySQL进程风险过高,予以排除。
>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 rows in set (0.01 sec)
优雅方案:关键参数在于审计插件的日志刷新指令。
它类似于MySQL的FLUSH LOGS机制。
可借助进行特定的审计日志刷新指令(像对审计日志配置予以调整或者促使日志轮转被触发),来告知MySQL将审计日志文件关闭掉,而后再重新把它打开。
执行该操作后,文件句柄被释放,磁盘空间完全回收。
优化总结与SQL性能深度思考
经过两轮排查,日志引发的问题得到根治。
# lsof|grep delete mysqld 3218 mysql 5u REG 253,0 26946 85458954 /data/mysql_4350/tmp/ib6i5l8w (deleted) mysqld 3218 mysql 6u REG 253,0 0 85458955 /data/mysql_4350/tmp/ibzgbLJz (deleted) mysqld 3218 mysql 7u REG 253,0 0 85458956 /data/mysql_4350/tmp/ibUZDalC (deleted) mysqld 3218 mysql 8u REG 253,0 0 85458960 /data/mysql_4350/tmp/ibhdSF1K (deleted) mysqld 3218 mysql 12u REG 253,0 0 85458961 /data/mysql_4350/tmp/ibo46oDR (deleted) mysqld 3218 mysql 41w REG 253,0 635612876075 85460307 /data/mysql_4350/data/audit.log (deleted)
本次事件给数据库运维带来了深刻的启示:
精细化的日志管理方面,于高并发压力测试的场景当中,建议针对审计日志比如audit插件予以关闭或者进行降级处理,仅仅是在有需要的时候才将其开启。
倘若一定要开启,那就得规划好日志的自动进行轮转以及切割的策略,以此来防止单个文件变得过大。
2. 测试里发觉,在极高压力状况下,1 - 2分钟就诞生1GB慢日志,这表明并发效率极其低,而慢查询恰似性能所用的镜子。
# ps -ef|grep 3218 mysql 3218 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 root 87186 86999 0 15:20 pts/0 00:00:00 grep 3218
这不但体现出SQL编写的质量情况,反而还暴露出索引缺失的状况,以及数据量庞大的情形,或者锁竞争极为严重的问题。
持续地进行SQL逻辑的优化,同时将索引设计加以调整,如此一来,能够明显降低无效日志的输出量,进而使得系统的吞吐量得到提升。
3. 故障自愈与监控:这类问题非常适合接入自动化处理。
借助监控磁盘使用率阈值,当触发告警之后,能够联动执行预设脚本,像动态刷新日志或者归档之类的,达成故障的自我修复,缩减响应时间。
通过这次排除错误,我们不但清理了磁盘的空间,而且对于数据库在极端压力状况下的行为模式有了更为深刻的认识,为往后的性能调整优化以及架构加强稳固积攒了珍贵的经验。
>set global audit_log_flush=on; Query OK, 0 rows affected (10.04 sec)

Comments NOTHING