高并发场景下disk io造成的高时延问题

发现问题

该系统属于长连接消息推送业务，某节假日推送消息的流量突增，大量的消息待下推的消息，事后发现生产消息的业务服务端因为某 bug ，把大量消息堆积在内存，在一段时间后，突发性的发送大量消息到推送系统，这样压力一下子就上来了，但由于还未触发熔断器，消息依然进行流转。

最主要的因为是前些日子公司做成本优化，有一个可用区的机器从物理机迁移到阿里云内，机器的配置也做了***，导致消息时延从 < 100ms 干到 < 3s 左右。

分析问题

造成消息推送的时延飙高，通常来说有几种情况，要么cpu有负载？要么 redis 时延高？要么消费rocketmq 慢？或者哪个关键函数处理慢 ?

通过监控图表得知，load正常，且网络io方面都不慢，但两个关键函数都发生了处理延迟的现象，该两函数内处理redis和mq的网络io操作外，基本是纯业务组合的逻辑，讲道理不会慢成这个德行。

询问基础运维的同学得知，当时该几个主机出现了磁盘 iops 剧烈抖动, iowait 也随之飙高。但问题来了，大家都知道通常来说linux下的读写都有使用 buffer io，写数据是先写到page buffer里，然后由内核来flush，但当脏写率超过阈值时，业务中的write会被堵塞住，来进行同步刷盘。

推送系统的日志已经是INFO级别了，虽然日志经过特殊编码，空间看似很小，但消息的流程依旧复杂，不能不记录，每次扯皮的时候都依赖这些链路日志来甩锅。

阿里云主机普通云盘的 io 性能差强人意，以前在物理机部署时，没出现这问题。

解决思路

通过监控的趋势可分析出，随着消息的突增造成的抖动，我们只需要解决抖动就好了。上面有说，虽然是buffer io写日志，但随着大量脏数据的产生，来不及刷盘还是会阻塞 write 调用的。

解决方法很简单，异步写不就行了 !!!

• 实例化一个 ringbuffer 结构，该 ringbuffer 的本质就是一个环形的 []byte 数组；
• 为了避免 OOM, 需要限定最大的字节数；为了调和空间利用率及性能，支持扩缩容；
• 抽象 log 的写接口，把待写入的数据塞入到ringbuffer里；
• 启动一个协程去消费 ringbuffer 的数据，写入到日志文件里；
  • 当 ringbuffer 为空时，进行休眠百个毫秒；
  • 当 ringbuffer 满了时，直接覆盖写入。

这个靠谱么？ 我以前做分布式行情推送系统也是异步写日志，据我所知，像 WhatsApp、腾讯QQ和广发证券也是异步写日志。对于低延迟的服务来说，disk io造成的时延也是很恐怖的。

覆盖日志，被覆盖的日志呢？ 异步写日志，那Crash了呢？ 首先线上我们会预设最大 ringbuffer 为200MB，200MB足够支撑长时间的日志的缓冲。如果缓冲区满了，说明这期间并发量着实太大，覆盖就覆盖了，毕竟 系统稳定性和保留日志，你要哪个 ？

Crash造成异步日志丢失？针对日志做个metrics，超过一定的阈值才进行开启异步日志。但我采用的是跟广发证券一样的策略，不管不顾，丢了就丢了。如果正常关闭，退出前可优雅可选择性阻塞日志缓冲刷新完毕。如果Crash情况，丢了就丢了，因为golang的panic会打印到stderr。

结论

如有全量日志的需求，建议分两组 ringbuffer 缓冲区，一个是debug的，一个是其他level的，好处在于互不影响。还有就是做好缓冲区的监控。

下面是我们集群中的北京阿里云可用区集群，高峰期消息的推送量不低，但消息的延迟稳定在 100ms 以内。