记一次阿里云日志导致的服务宕机

导航

• 引言
• 火线告警，访问502
• 猜测: I/O频繁惹的祸
• 真相：FullGC突发高频导致程序崩溃
• 移除阿里云日志，稳了
• 结语
• 最后
• 参考

引言

技术人应该具备系统分析，并快速定位问题的能力。

资深技术人需要具备的核心竞争力有哪些？

• 系统分析，并快速定位问题的能力
• 快速地理解需求，转化为流程，架构，并文档输出的能力
• 有一定的产品设计能力，关键时刻可以纠正不良产品设计
• 快速组织人干事的能力

这里的每一项能力都很关键，但是最重要的还是拥有第一项能力。

毕竟，解决问题才是关键。

继上次《记一次加锁导致ECS服务器CPU飙高分析》之后，后面又陆陆续续地遇到并解决了一些新的问题。一直想着记录一下，但是终究因为各种原因没能下笔。

今天给大家分享一下阿里云日志引发的服务宕机问题的解决过程。

火线告警，访问502

项目背景介绍

今年Q2我接管了一个Java项目，接口服务是基于SpringBoot技术框架实现的，部署在阿里云的sae上（SAE是一款 Serverless理念的微服务应用框架）。

配置如下：

• 实例规格: 2Core, 2GiB, 系统盘磁盘空间20GiB
• 运行实例数: 当前2个实例

监控扩容策略:

• 应用扩缩触发值：满足 cpu > 66%
• 应用最小实例数: 2
• 应用最大实例数: 10

该服务是是TOB业务，服务于2000家小微企业。

这里以2023.9.15日监控数据来看，在工作时段(09:30~18:00)，单个实例总TCP连接数平均值约为4K左右。

问题描述

自从进入8月中旬以来，几乎每天都会在报警群里面，收到502告警通知。
这种通常是SAE已经出现自动扩/缩容，导致释放实例出现告警。

每天都会有2~3次报警，可能发生在上午或者下午或者两者都有,让人不厌其烦。

从用户第一的角度，这个老是自动扩容和释放肯定是不友好的。
而B端用户也容易拿这个说事儿，把问题放大。

从技术保障的角度看，这个服务的稳定性是值得商榷的，更不要谈4个9的指标了。

所以，解决服务稳定性是头等大事。

猜测: I/O频繁惹的祸

我连续跟踪了sae的监控日志，并对连续几次扩容时间点的各项指标进行了对比。
初步发现可一个规律: 即每一次触发扩容的cpu飙升，都是伴随着IOPS飙升的。

上图是总体指标，实际上单实例的指标在此之上。

初步断定，程序中可能有功能涉及到磁盘的大量读写，比如文件上传，可能触发了IOPS飙升。

阿里云存储云盘IOPS

IOPS即Input/Output Operations per Second，阿里云服务器存储系统盘IOPS指每秒能处理的I/O个数，IOPS表示块存储处理读写（输出/输入）的能力，单位为次。

部署事务密集型应用，如数据库类应用等典型场景，需要关注IOPS性能，只有挂载到I/O优化的实例时，SSD云盘才能获得期望的IOPS性能。IOPS指标说明：

于是查看阿里云日志，发现还真有个文件上传接口存在性能问题

有图有真相，这更加让我坚信是这个接口导致的问题。

于是连夜做了性能优化，快速上线。

真相：FullGC突发高频导致程序崩溃

道路是曲折的,前途是光明的。

如果仅仅是优化了上面这个接口就能解决，那这个问题也不值得我为此专门写一篇文章了。

实际情况是，第二天，可恶的502问题又出现了。

一筹莫展之际，同组的有个伙伴，这个项目在我接管之前，他是参与时间最长的开发。
他说可能是FullGC频率太高导致。

JVM监控功能用于监控重要的JVM指标，包括堆内存指标、非堆内存指标、直接缓冲区指标、内存映射缓冲区指标、GC（Garbage Collection）累计详情和JVM线程数等。
详细请查看《JVM监控》

于是我们一起看了监控中jvm的指标，下面我整理的9.11当天的FullGC和YoungGC指标。

经过观察，发现FullGC的频率确实偏高，每分钟大概在2~6次。
可以很明确的判断高频的FullGC是服务自动重启的罪魁祸首。

移除阿里云日志，稳了

在断定是FullGC高频这个根本原因之后，我们也做过一种方案，那就是修改JVM调参。

当然，尝试过几次之后，效果不理想，依然每天都出现502。关于JVM调参这个有兴趣的同学可以自己研究。

Log4j

在抛出我的解决方案之前，请允许我介绍一下Log4j。

Log4j是Apache的一个开放源代码项目，通过Log4j可以控制日志的优先级、输出目的地和输出格式。日志级别从高到低为ERROR、WARN、INFO、DEBUG，日志的输出目的地服务器托管网指定了将日志打印到控制台还是文件中，输出格式控制了输出的日志内容格式。

例如某电商公司，希望通过分析用户行为习惯数据（例如用户登录方式、上线的时间点及时长、浏览页面、页面停留时间、平均下单时间、消费水平等）、平台稳定性、系统报错、数据安全性等信息获取平台的最佳运营方案。

阿里云日志服务提供一站式数据采集与分析功能，帮助客户存储并分析日志。

所以，我们的大部分java项目也使用的log4j这个日志库。

• 关于阿里云记录日志可以查看这里：aliyun-log-log4j-appender
• 关于sprigboot,初学者可以参考《Spring Boot 实战纪实(附源码)》

而我的解决方案正好与log4j接入阿里云日志接口相关。

移除阿里云日志

程序中接入阿里云日志，本省就是通过sdk调用接口的过程，即便性能再好的接口，在每分钟3000+次时调用的情况下，也是会暴露出性能的问题。即便阿里云接口抗住了，恐怕我们自己的服务也处理响应不过来。

为啥我会怀疑是阿里云日志的调用问题呢？

恰好我在6月份处理过一个nodeJs项目cpu高的问题。

这个nodeJs项目也是部署在sae上的，是一个群聊的聊天服务器，正常情况下cpu使用率在20%左右，但是在socket连接数大于3k之后，群发消息cpu会急剧飙升。

这个也是我经过差不多一周时间的跟踪，并且在服务器上做了压测复现了的。

而他的最终解决方案就是将程序中阿里云日志服务上报，改成输出到控制台，再由sae再推送给阿里云logstore。

所以，整合了sae 基础监控、JVM指标、阿里云日志网关调用记录，我猜测他们可能本质上属于一类问题。

不管如何，我决定尝试一下。

说干就干，我将Java项目中阿里云日志接口移除，只保留控制台输出。
另外，补充说明一下,只要是输出到控制台日志，sae可以配置logstore,然后转存到指定的阿里云logstore。

令人欣喜的是，第二天，线上没有再报502，连续五天去了，依然稳健。
阿里云日志去除是9.11晚上线的，9.12~9.13两天的jvm监控如下:

从图中可以看到，FullGC的频率始钟控制在1次/min,同时我也统计了单日YongGC的总次数下降了一半。

至此，502的问题总算得以根治。

结语

程序是是有生命的，只要被使用就一定会随着业务的增长，带来新的问题。

解决这些问题的方式很多，一种是升级配置，一种是优化代码。

而很多时候，为了降本增效，我们不得不优化代码。

而这些优化的方式你可以从前辈们的分享中获取，但是很多问题可能是还得自己去摸索。

学习-实践-分享-萃取，周而复始，让知识和经验薪火相传，这也是博客的价值。

希望我的分享能够给你带来帮助，哪怕只是帮你节省了一点点喝咖啡的时间。

最后

这里再啰嗦两句，我们将业务日接入阿里云日志服务，主要是方便后续的日志查询。这个和我们使用ELK搭建日志服务异曲同工。

本文中遇到的问题不是阿里云日志的问题，只是我服务器托管网们的项目接入阿里云日志的方式不太适合当下的场景。我们选择将直接记录改成了异步方式记录，这个有利于降低业务服务器的压力(考虑到我们购买的服务器实例配置太低了,仅有2核2G)。

码字不易，欢迎各位老铁点赞、转发。

参考

• 分析Log4j日志
• 《记一次加锁导致ECS服务器CPU飙高分析》
• 《记一次阿里云日志导致的服务宕机》

服务器托管，北京服务器托管，服务器租用 http://www.fwqtg.net
机房租用，北京机房租用，IDC机房托管， http://www.fwqtg.net