今天早上,我差点没被那声警报声给吓死,直接从床上弹起来了。当时才八点刚过,我正准备出门去楼下买个煎饼,手机就跟抽风一样,开始疯狂地推送“234服务中断”的警告。
这个234服务,说白了,就是我们内网跑的一个小东西,负责把一些测试数据做个初步的清洗和分发。虽然不是啥核心业务,但它一旦停了,后面一堆测试环境都会卡壳,到时候等着我的就是一连串的电话轰炸。我当时心里就一个想法:完了,又出幺蛾子了。
检查第一步:它到底死没死?
我顾不上穿外套,抓起电脑就往沙发上一坐,赶紧先确认是不是真的死了。经验告诉我,有时候监控系统也会抽风,虚惊一场是常有的事。我先是尝试从浏览器访问那个简单的测试页面,果然,一片空白,连个“404”都没有,就是超时,连接直接被拒绝了。
这下我懵了,连接被拒绝,说明它压根儿就没在听。我立刻登录了那台服务器,一个简简单单的ping过去,网络是通的,说明主机没挂。这更奇怪了,主机活着,服务却不理人。
我赶紧SSH进去,第一件事情就是查看进程。
- 我敲了
ps -ef grep 234,结果看到了,进程ID在那儿挂着! - 但是,这个进程的CPU和内存占用都低得离谱,几乎不动弹。
- 我试图用
kill -9把它干掉,然后重启。
我心想重启大法应该是万能药?结果,服务是重启了,但是启动脚本跑完之后,服务还是无法访问。我试了两次,都一样,它就是启动不了,或者说,启动了马上又自我关闭了。
这时候我已经开始有点冒汗了。这不像是代码bug,代码bug一般是启动失败或者运行崩溃,但这回是进程活着,却完全不工作。我意识到,这肯定是个非常低级,但是又非常隐蔽的问题。
深入排查:去看日志,却找不到线索
服务启动失败,最直接的证据肯定在日志里。我马上跑去日志目录,准备看看启动脚本到底报了什么错。我找到了最新的那个日志文件,用tail -f看着。
日志显示,服务已经尝试连接数据库,并且完成了几个必要的初始化步骤,看起来一切顺利。但是,就在它准备进入主循环开始监听端口的时候,日志突然就停了,像被掐住了脖子一样,一句话都不再往外吐。
我当时真的挠头了。难道是内存不够?我赶紧看了看内存使用情况:free -m。结果显示,内存还绰绰有余,只用了不到一半。
难道是依赖项突然失效?我查了查连接的数据库和缓存服务,都运转得好好的。
没办法了,我只能再回过头,对着日志文件,一寸一寸地看,想看看一句记录的是什么鬼东西。正当我打算用Vim打开日志文件的时候,命令行突然报错了。不是日志文件的报错,是系统告诉我:“磁盘空间不足!”
我当时整个人都僵住了。这么低级的错误,我竟然差点忽略了!
最简单的解决方法:发现元凶,一刀切掉
我赶紧输入了那个拯救过我无数次的命令:df -h。
这一看,我差点没气乐了。果然,挂载服务所在的那个分区,使用率赫然写着:100%。
服务打不开,不是因为它代码有问题,也不是因为它依赖项挂了,而是因为它在尝试写入新的日志时,发现系统盘满了,写不进去,所以整个进程就卡住了,无法继续执行下去,连监听端口都做不到。这真是典型的“被自己撑死”的案例。
现在问题简单了,找到是谁占用了空间,然后把它干掉。
我用du -sh 在根目录下逐层排查,最终定位到了日志目录。好家伙,一个叫debug_*的文件,已经长到了惊人的三百多G,几乎把整个分区都给占满了。我这才想起来,上周有个新人跑了一个压力测试,可能忘了把日志级别调回来,导致所有的调试信息全给打进去了。
我的处理方式很简单粗暴:
- 第一步: 赶紧用
rm -rf debug_*,把它彻底删掉,释放空间。 - 第二步: 重新检查
df -h,确认空间已经清空,使用率降到了可怜的5%。 - 第三步: 再次执行启动脚本,重启234服务。
这回日志开始哗地往外吐了,我看到它成功监听了端口,并且在浏览器里重新刷新,服务页面秒开!234终于打通了!
整个过程从我接到警报到服务恢复,只花了不到半小时,但其中有二十分钟都在瞎琢磨CPU和内存。这事儿给我最大的教训就是,当你发现一个程序好像活着又像死了的时候,别急着看什么复杂的程序堆栈,先看看最基础的“水电煤”供应足不足。很多时候,系统不是被复杂的bug搞定的,而是被最简单的资源耗尽给卡死的。以后,我们必须得把日志轮转这个事情给安排到位,不能让这种低级错误再来浪费我的煎饼时间了。