线上服务被干爆了,居然是日志的锅!!

本文要介绍的是一个发生在咱们线上环境的真实案例,问题发生在某次大促期间,对咱们的线上集群形成了比较大的影响,这篇文章简单复盘一下这个问题。问了方便你们理解,实际排查和解决过程可能和本文描述的并不彻底一致,可是思路是同样的。程序员

问题过程

某次大促期间,某一个线上应用忽然发生大量报警,提示磁盘占用率太高,一度达到了80%多。数据库

这种状况咱们第一时间登陆线上机器,查看线上机器的磁盘使用状况。使用命令:df查看磁盘占用状况。服务器

$df
Filesystem     1K-blocks    Used Available Use% Mounted on
/               62914560 58911440 4003120  93% /
/dev/sda2       62914560 58911440 4003120   93% /home/admin

发现机器磁盘确实耗费的比较严重,由于大促期间请求量比较多,因而咱们最早开始怀疑是否是日志太多了,致使磁盘耗尽。网络

这里插播一个背景,咱们的线上机器是配置了日志的自动压缩和清理的,单个文件达到必定的大小,或者机器内容达到必定的阈值以后,就会自动触发。运维

可是大促当天并无触发日志的清理,致使机器磁盘一度被耗尽。工具

通过排查,咱们发现是应用的某一些Log文件,占用了极大的磁盘空间,而且还在不断的增大。操作系统

du -sm * | sort -nr
512 service.log.20201105193331
256 service.log
428 service.log.20201106151311
286 service.log.20201107195011
356 service.log.20201108155838

du -sm * | sort -nr :统计当前目录下文件大小,并按照大小排序计算机网络

因而通过和运维同窗沟通,咱们决定进行紧急处理。日志

首先采起的手段就是手动清理日志文件,运维同窗登陆到服务器上面以后,手动的清理了一些不过重要的日志文件。code

rm service.log.20201105193331

可是执行了清理命令以后,发现机器上面的磁盘使用率并无减小,并且仍是在不断的增长。

$df
Filesystem     1K-blocks    Used Available Use% Mounted on
/               62914560 58911440 4003120  93% /
/dev/sda2       62914560 58911440 4003120  93% /home/admin

因而咱们开始排查为何日志被删除以后,磁盘空间没有被释放,经过命令,咱们查到了是有一个进程还在对文件进行读取。

lsof |grep deleted
SLS   11526  root   3r   REG   253,0 2665433605  104181296 /home/admin/****/service.log.20201205193331 (deleted)

lsof |grep deleted 的做用是:查看全部已打开文件并筛选出其中已删除状态的文件

通过排查,这个进程是一个SLS进程,在不断的从机器上读取日志内容。

SLS是阿里的一个日志服务,提供一站式提供数据收集、清洗、分析、可视化和告警功能。简单点说就是会把服务器上面的日志采集到,持久化,而后供查询、分析等。

咱们线上日志都会经过SLS进行采集,因此,经过分析,咱们发现磁盘空间没释放,和SLS的日志读取有关。

到这里,问题基本已经定位到了,那么咱们插播一下原理,介绍一下这背后的背景知识。

背景知识

Linux系统中是经过link的数量来控制文件删除的,只有当一个文件不存在任何link的时候,这个文件才会被删除。

通常来讲,每一个文件都有2个link计数器:i_count 和 i_nlink,也就是说:Linux系统中只有i_nlink及i_count都为0的时候,这个文件才会真正被删除。   

  • i_count表示当前文件使用者(或被调用)的数量
  • i_nlink表示介质链接的数量(硬连接的数量);
  • 能够理解为i_count是内存引用计数器,i_nlink是磁盘的引用计数器。   

当一个文件被某一个进程引用时,对应i_count数就会增长;当建立文件的硬连接的时候,对应i_nlink数就会增长。

在Linux或者Unix系统中,经过rm或者文件管理器删除文件,只是将它会从文件系统的目录结构上解除连接(unlink),实际上就是减小磁盘引用计数i_nlink,可是并不会减小i_count数。

若是一个文件正在被某个进程调用,用户使用rm命令把文件"删除"了,这时候经过ls等文件管理命令就没法找到这个文件了,可是并不意味着这个文件真正的从磁盘上删除了。

由于还有一个进程在正常的执行,在向文件中读取或写入,也就是说文件其实并无被真正的"删除",因此磁盘空间也就会一直被占用。

而咱们的线上问题就是这个原理,由于有一个进程正在对日志文件进行操做,因此其实rm操做并无将文件真正的删除,因此磁盘空间并未释放。

问题解决

在了解了线上的问题现象以及以上的相关背景知识以后,咱们就能够想到办法来解决这个问题了。

那就是想办法把SLS进程对这个日志文件的引用干掉,文件就能够真正的被删除,磁盘空间就能真正的被释放掉了。

kill -9 11526
$df
Filesystem     1K-blocks    Used Available Use% Mounted on
/               62914560 50331648 12582912  80% /
/dev/sda2       62914560 50331648 12582912  80% /home/admin

特别提醒下,在执行kill -9 以前,必定要考虑下执行的后果是什么,背后原理能够参考:我到服务器执行kill -9后,就被通知次日别来了!

过后,咱们通过复盘,发现之因此出现这样的问题,主要有两个缘由:

  • 一、线上日志打印太多,太频繁
  • 二、SLS日志拉取速度太慢

深刻分析后咱们发现,这个应用打印了不少过程日志,最初日志打印是为了方便排查线上的问题,或者作数据分析用的,可是大促期间日志量激增,致使磁盘空间占用极速上升。

另外,由于该应用和几个其余的大应用共用了一份SLS的project,致使SLS拉取速度被拉低,进而致使进程一直没法结束。

过后,咱们也总结了一些改进项,对于第二个问题,咱们对于该应用的SLS配置作拆分,独立出来进行管理。

对于第一个问题,那就是大促期间引入日志降级的策略,一旦发生磁盘爆满,就是将日志降级掉。

关于日志降级,我开发了一个通用的工具,就是经过配置的方式,动态推送日志级别,动态修改线上的日志输出级别。而且把这份配置的修改配置到咱们的预案平台上,大促期间进行定时或者紧急预案处理,便可避免这个问题。

关于日志降级工具的开发思路和相关代码,下一篇文章中给你们分享。

思考

每次大促以后咱们复盘,都会发现其实大多数问题都是由几个不起眼的小问题堆积到一块儿而引起的。

在问题分析过程当中每每会须要运用到不少非开发技能相关的知识,如操做系统、计算机网络、数据库、甚至硬件相关的知识。

因此我一直认为,判断一个程序员是否牛X,就看他的解决问题的能力!

相关文章
相关标签/搜索