前言

众所周不知,我在 24 年底入职了某连锁品牌的美甲公司,负责相关小程序和后台的开发与维护。

入职前了解到该项目最初由外包团队开发,并使用外包三件套:宝塔、TP、Mysql 进行部署和搭建,当时我心里就对它有了一个大概的印象,但是等我真正接手这个项目时,还是忍不住地两眼一黑,心头有一万头草泥马奔腾而过。

项目结构之混乱,方法定义之奇葩,没有一项不在挑战我认知的下限,我只能说,用屎山来形容这套代码都是在夸它,项目能平稳运行简直就是个奇迹。

哦,也不能算奇迹,因为这勾八玩意儿就没有一天是平稳的。

在告别了手动替换服务器代码并用 git 管理之后,我又先后经历了 CDN 欠费,小程序图片无法正常显示;SSL 证书过期,所有服务全部宕机;以及子项目域名过期却拿不到平台账号,最后只能换绑域名这样的种种混乱……

在此之后,系统总算平稳运行了几天。

屎山的崩塌

正当我撸起袖子,准备奋力重构这坨屎山时,年底到了,我又迎来了新一波的挑战。

1 月 16 号早上 10 点,我把手里刚开发完的小程序推送到正式版,之所以选在这个时间更新,是因为有些门店会营业到凌晨5点,10 前的使用量相对还少一些。

本来只是一个简单的更新操作,但是让我没想到的是,刚发版没一会儿,运营就突然在群里反馈说小程序卡,很卡,非常卡。

我被这消息搞得一头雾水,貌似刚才也没写 bug 吧?

掏出手机操作一下,发现确实不能正常使用,阿西吧,赶紧联系同事撤回了版本。

这回总好了吧?掏出手机一看,还是不正常,群里也还在不停反馈依然无法登录等各种问题,傻眼的我更傻眼了。

打开服务器上的宝塔面板,两眼又是一黑,负载已经飙到了 100%,cpu 也到干了 94.5%。

wtf?这可是三台配置都不算低的服务器,按照上家公司的业务量,这个配置估计只需要一台就足够了。

我赶紧打开 nginx 的 access 日志,结果发现啥也没有,因为配置文件里压根儿就没有记录日志的代码。

再一问同事,之前服务器硬盘被日志塞爆过,没人清理,后来索性就都关了。

我无语凝噎。只能硬着头皮继续分析,发现负载和 cpu 飙升的原因是有几个 php-fpm 进程占用特别高。

它们在干啥?为什么会飙这么高?

正当我们抓耳挠腮,掉了无数头发时,又在云服务器后台发现前一天 0 点也有同样的情况。

再往前一翻,清一色的 0 点和 10 点各项指标飞速飙升,0 点的飙升像座小山,10 点的飙升像座大山。

wō ní mǎ。

开始抓虫

我慌了,开始怀疑起这个项目有异常的定时任务。

我的怀疑是有根据的,因为前一波开发的大聪明在调接口时,借助框架的事件驱动模块,用嵌套了两层的 http 接口调用一个所谓的 Task 接口,然后触发了 1000 多个 event……

为什么要套两层接口,我不知道,为什么要这样写,我也不知道。

我只知道本地的接口被这玩意儿拖到了 6 秒一个请求,开发需求时我都是直接把这行代码注释的。

事情到了这个节骨眼上,我只能硬着头皮研究了一下这块代码,然后清除了里边 90% 左右的无用事件,然后又仔细检查了服务器的 crontab,emmm,就没有在 0 点和 10 点运行的任务。

查到这里事情还是没有大的进展,我的心态已经开始波动了,这屌系统崩就崩吧,这屌工作要不就干到今天算了吧?要不等过了年,我再出去找找其他工作?

正当我想要打开 boss 直骗,给自己发昏的大脑来上一套强制冷却时,系统又诡异地恢复了平静。

我挠着头,一边感叹自己对这个屌系统的认知还是太过于浅薄,一边思考为什么会出现这样的局面,这里边还有没有什么其他值得怀疑的对象。

这时候,运营又在群里反馈了其他问题,我看这一波飙升已经过去,下一波也还很遥远,也就先放下了这件事,先去处理群里的其他问题。

时间一晃到了下午,闲下来的我和同事又发现数据库有很多慢 sql,其中一个最夸张的甚至运行了 126 秒。

是它吧?一定是,要不然还能是谁呢?

我和同事马上开工,把系统里的慢 sql 都给优化了一遍,然后又给服务器装了 Atop 做监控,信心满满地等着 0 点时验证一波。

时间再次来到 0 点,服务器准时出现波动,但是只有 10 秒。

我先打开慢 sql 日志,完美,没有慢sql。再一看 Atop,10 分钟一次的记录完美避开的案发现场。

这样下去明天 10 点铁定得崩,那咋办?还有台闲置的服务器,加上去吧,看看后台,还有门店在使用系统,那只能等明天早上再加。

跟同事约好第二天早上 5 点半起来操作,我估摸这要不把 access 日志打开,看看涌进来的请求是不是都正常,因为这个时候已经开始怀疑是不是被人攻击了。

第二天一早,我们爬起来先把昨天推送失败的小程序再次更新,验证完之后又把新服务器加进了负载,忙完以后定了个 9 点多的闹铃,然后赶紧躺下又眯了一会儿。

不到 10 点,又被群里的消息吵醒,看完发现是前一天优化的 一条 sql 有问题,没有正常生成数据,快 10 点了,我们把问题先丢在一边,先盯着监控看服务器状态。

结果很快再次打脸,新增的服务器虽然也扛住了很多并发,但系统还是崩了,大量用户无法排队,大量门店也无法叫号,这次挣扎再次以失败告终。

我把 access 日志拉了出来,逐行分析了上千行日志,发现事情并没有那么简单,这些请求似乎都很正常,难道攻击我们的还是个高手,伪装成了正常用户?

我统计了每个接口的访问数量,又统计了每个 token 访问的接口数量,还解析了几个用户的 token。但是,这些东西还是没有任何帮助,我没有找到任何被攻击的证据。

事情再一次陷入僵局。

令人无语的真相

时间再次来到 0 点,我们提前停下了所有定时任务,系统不出所料,还是全线飘红,不过我们好在知道了问题的根源是在数据库。

但是为什么会在 0 点和 10 点这两个时间涌入大量的请求,我们还是怀疑是不是有人在攻击我们,苦于没有证据,只能继续分析日志。

我们发现在 0 点的一瞬间,系统涌入大量的排队操作,其他调查均无成效的情况下,我们只能统计了 0 点后每家门店的排队情况,打算第二天联系门店核实一下这些排队是否真实,同事也把我们统计的表格发给了老板。

每个人的心头都像压了一座大山,怎么办,再不搞定这个年还能过好吗?

第二天浑浑噩噩地爬起床,灌下一杯超浓咖啡,我带着深深的忧虑再次上班。

路上,同事发来一张聊天截图,老板说,这些是正常的,很多门店就是 0 点开始放号,因为每个门店的排号是有限的,顾客只能在放号的一瞬间去抢,包括十点也是一样的情况。

我觉得天塌了,忍不住骂一声他喵的,合着我们起早贪黑辛苦调查,最后调查了个寂寞,系统宕机纯粹就是因为瞬时并发太大???

wtf!这个世界是真的魔幻啊,做个美甲还要 0 点起来抢号?

波折的解决之路

时间一晃又到 0 点,我们白天把排队叫号相关的接口逐个优化,该加缓存的也都加上了缓存,同事也研究起数据库的从库和代理,等着 0 点验证一下能否扛住压力。

然后,我们卡在了第一步,读库连不上去,服务器方面,靠着手动切换负载,硬是扛住了这一波。

再一看日志,排号接口平均在 20 毫秒,叫号接口平均在 250 毫秒,但是读库的内存才使用了 17%,像极了你那个出工不出力天天在摸鱼的老油条同事。

阿西吧,这可不行。

读库可是按小时收费的,扛过了零点高峰,我们马上下了,准备第二天早上继续研究。

第二天一早又把读库配好,也让运营通知了门店错峰放号,我紧盯着监控,准备随时切换负载分配,同事那边也在联系服务器客服,让他们远程协助,解决读库不发力的问题。

但是很遗憾,10 点前读库的问题还是没能解决,服务器小崩了一下。

时间已经到了周日,距离放假还有一周,距离第一次触发这种情况已经过去一周还要多,再不解决,真就过不好这个年了呗。

虽然这是个从系统诞生就已经存在的问题,但在业务高峰期频繁触发实在打脸,老板拉我们开了个会,说以前的人是把服务器的流量降下来,听得我们目瞪狗呆,这是什么傻逼骚操作?降流量,咋不把服务关了呢。

一番拉扯后,我们决定给接口限流,10-10:30 期间,每分钟放出 100 个排号,超出就等下一波。

方法测完上线后,我们终于迎来了第一个好消息,读库能连上了。

当即选了一台服务器切了过去,然后进行了一波测试,发现读库还是有点慢,有点鸡肋。

同事再次提了工单,在对方的大力协助下,我们升级了读库和代理的配置,几乎是在一瞬间,主库的 cpu 睡着了。

0 点后,qps 一路狂飙到了 18000/s,服务器的负载虽然又到了 100%,但是 cpu 一直维持在 80% 左右,这件事总算成了。

我特么能睡个好觉了……