Continuous profiling 拯救了 Victoria Metrics

• 即将退出历史的舞台 - 普罗米修斯
• 时代的新秀 - 维多利亚
• 吃螃蟹的代价 - 踩坑
• 普罗米修斯拯救维多利亚 - 用监控系统来分析监控系统的问题
• 外科手术刀 - 火焰图
• 积食，不是吃的太多，就是消化太慢 - 数据的积压
• 专家会诊 - 求助开发团队
• 好奇心，先放一放 - 解决锁的问题
• 精准武器 - Continuous profiling
• 普罗米修斯的锅 - 数据缺失
• 找到病灶 - 限流
• 一个老难题 - 资源配额
• 切除阑尾 - 开发团队的做法

即将退出历史的舞台 - 普罗米修斯

普罗米修斯(Prometheus)作为第一代的云原生监控系统，已经走过了整整10个年头，其丰富的功能特性、强大的数据模型等特点赢得了广大的用户，成为最主流的监控系统之一。

当今云原生的复杂度已今非昔比，分布式、海量数据、高可用等使prometheus越来越难以满足用户的需求。

我们同样面临这些问题，服务、指标、机器数量都在增长，而prometheus的单点化、低压缩率导致运维和资源成本不断增加；监控指标存储时间较短，需要久远历史数据进行分析时往往又爱莫能助，因此需要新一代的监控系统来替换现有的prometheus。

• 可以直接看微信公众号文章：https://mp.weixin.qq.com/s/duqoTGgeM_1kdwWsdvI3ZA
• 也可以同时关注我微信公众号，有很多优质文章：【技术闲聊吧】

时代的新秀 - 维多利亚

要引进新技术，最大的阻力莫过于历史的包袱。我们希望不影响用户体验及无缝整合现有基础设施，那无异于给一辆高速行驶的汽车换轮胎，所以新系统最好能兼容prometheus接口。

经过调研，最后决定使用维多利亚(Victoria Metrics)，其架构简单，可靠性高，在性能、成本、可扩展性方面表现出色，而且兼容prometheus接口。

现有prometheus集群规模，只保留2个月的数据，同样的机器下数量下，VM能够保留1年，而且是双副本，收益非常明显。

吃螃蟹的代价 - 踩坑

经过一系列测试，我们对VM(Victoria Metrics)的功能非常满意；但在做性能测试时，VM就出现了严重的CPU抖动问题。

VM集群中的1个节点的CPU利用率会偶发性地飚高到100%，持续一段时间后又会自己恢复。

从下图中可以看出节点13 CPU突然增高到97%，持续了2个多小时后恢复正常，其中读写QPS抖动非常严重，但是大多数时候持续时间较短。

节点13和其他节点的差异：13的磁盘是SSD，而其他节点是HDD，高配机器反而出问题了？

普罗米修斯拯救维多利亚 - 用监控系统来分析监控系统的问题

我们使用prometheus收集VM的监控指标来进行分析，从监控大盘的来看，问题发现时：

• CPU利用率 涨到100%
• 内存
  • index block 的cache size快速上涨
  • storage/inmemory快速上涨
• 磁盘
  • 写：写入量降低CPU就开始涨，写入量上涨CPU将降低了，延迟并没有变化
  • 读：读取量降低（同时读QPS降低），延迟并没有变化
• 请求
  • 读：返回的blocks数量上涨
  • 写：QPS降低，slow write增加，并发写增加

什么是index block？谁又是storage/inmemory？很多指标都有异常，由于不了解VM原理，又怎么知道这些指标代表什么？

掀开引擎盖去了解每一个零件是不可能的，所以只能先从字面意思来推测这些指标的用途。index block应该是索引块，可能代表读请求缓存的索引数据，而storage/inmemory应该是写入请求的内存缓冲块(很多存储引擎都这么命名，后面证明也确实如此)。

然而，监控指标的采集是有时间间隔的，指标的上涨非常快速，所以从监控大盘看不出其中的因果关系。

那么日志呢？系统、内核、服务日志都没有异常，只有问题发生时有写入和查询请求的超时日志，这说明不了什么。

外科手术刀 - 火焰图

表象看不出问题，那么就上剖析武器，火焰图。

使用Go自带的pprof，通过on-CPU火焰图来分析耗时发生在哪里。

下图是节点13的火焰图：

正常节点的火焰图

通过对比正常节点火焰图可以看出，异常节点有不少比例的CPU时间消耗在几种锁的竞争上，还有不少是Less函数。

这。。。又能说明什么？SSD机器的缓存有锁问题，HDD机器就没有！

再结合之前监控系统的分析，发现其中干扰因素较多，无法分析具体因果关系，如：

• 出问题节点火焰图中没有写请求了，所以cache锁占比问题会被放大？
• Cache上涨和vm_parts(inmemory)关系？抢CPU？
• Slow write上涨，是磁盘写入慢导致还是由于CPU利用率太高导致写请求执行慢了？

阅读了一些源码以及翻阅VM的资料，有了一些基本的了解后，得出初步结论：

• vm_parts(storage/inmemory)上涨：
  • 导致读请求的blocks数量上涨，这是因果关系
  • 导致内存挤压很多小blocks，这就导致了Less函数调用次数上涨
• Cache size快速上涨，导致cache锁竞争

所以cache和vm_parts(inmemory)上涨导致锁竞争。

积食，不是吃的太多，就是消化太慢 - 数据的积压

那什么原因导致cache和vm_parts(inmemory)上涨呢？关系到写还是读？还是互相影响？为什么SSD的机器反而出问题？还是前期cache上涨导致的连锁反应？是否cache回收出问题了？

数量上涨，无外乎于要么是生产太快，要么是消费太慢导致的积压。

于是，添加了cache相关的监控，发现其回收等功能都没有问题。

再看看vm_parts(inmemory)，13是SSD，应该读写更快才对，不过这是理论知识，通过对SSD进行了持续压测，发现磁盘性能较好，没有问题（用同步IO，就能到50MB/s的写入速度，那么这块不是瓶颈），也没有抖动，所以不是消费问题。

那么很有可能就是生产太快导致积压，毕竟节点13是SSD，读磁盘更快，创建cache更快也更多，所以更容易导致积压。当然，这只是推测，还需要更进一步分析。

阅读了一些源代码，没有找出问题，为了更高效排查问题，还是先求助于VM开发团队吧。

专家会诊 - 求助开发团队

开发团队给了排查的方向 Troubleshooting，根据文档里的步骤，逐一排查，没有发现任何问题。

但开发团队也根据我们的指标做了一版优化，都是集中在Less函数优化上，有改善但并没有解决问题。

后来，开发团队也给不出建议了。。。。。。

好奇心，先放一放 - 解决锁的问题

无法弄清楚根本原因，这样耗下去也不是办法，既然知道是锁问题，那么先解决问题再说。

优化cache导致的锁竞争问题，有2个方案

• 降低cache容量：这个方案会影响读性能
• 加大cache分片：加大分片能降低分片内的锁竞争，副作用是不利于CPU缓存，不过，总比降低cache容量要好。

于是，优化index block cache，将分片数量从CPUs 16 逐渐调整到 CPUs 32，压力加大到2倍，问题得到较大改善，但并不稳定。

再优化fastcache（这块在火焰图中占比也不低）后，加大压力到4倍，CPU问题没有再出现了。但是会有偶发性的小幅度的QPS抖动，如下图

精准武器 - Continuous profiling

由于这种抖动是随机的，且持续时间很短，出现问题再去profiling问题又恢复了，所以适合使用continuous profiling工具进行分析。

Pyroscope是一款支持多语言的持续性能分析工具，对go语言支持较好，性能损耗较低，所以修改vmstorage代码，集成pyroscope。

静静地等待问题发生。。。

问题再次发生了，查询QPS从12:29:00开始下降，但从延迟QPS上看，最近时间点12:30:30只有节点3的延迟QPS上涨了(前期猜测可能延迟QPS有一定滞后性，因为VM的指标更新是定时的)，貌似是节点3的问题？

通过diff来对比节点3和正常节点的profiling数据，如on-CPU火焰图，block duration，mutex duration等看，节点3的指标都很正常！！！

有点怀疑人生了，难道哪个步骤出错了？

再逐一排查上面的分析，发现节点3的延迟QPS上涨其实和整体查询QPS下降是有1分钟的滞后的，这是个疑点。

打开延迟QPS指标，仔细查看每个节点后才发现节点10在12:29:50这个时间点缺少了数据，如下图

这个指标是 rate(vm_search_delays_total{}60s)，1分钟的聚合，所以其计算原理是1分钟内 (最后一个采样点 - 第一个采样点)/时间窗口，即rate = Δvalue / Δtime。

但在采集数据缺失的情况下，

• 如果最后一个采样点或第一个采样点不存在怎么办？prometheus直接将 rate 设置为0
• 如果两个采样点都不存在呢？则rate设置为null，那上图显示12:29:50时间点缺少的可能就是这个问题。

普罗米修斯的锅 - 数据缺失

通过prometheus接口拉取到vm_search_delays_total的原始采样数据，如下

## 原始采样点            

12:26:20 : 0            
12:26:35 : 0            
12:26:50 : 0            
12:27:05 : 0            
12:27:20 : 0            
12:27:35 : 0            
12:27:50 : 0            
12:28:05 : 0            
12:28:20 : 0            
12:28:35 : 0            
12:28:50            
12:29:05            
12:29:20            
12:29:35            
12:29:50            
12:30:05 : 31172047293            
12:30:20 : 31172047293            
12:30:35 : 31172047293            
12:30:50 : 31172047293            
12:31:05 : 31172047293            
12:31:20 : 31172047293            
12:31:35 : 31172047293

在原始采样点中，从12:28:50 到12:29:50 都没有采样到数据，所以如果在12:29:50时间点进行1分钟内聚合，计算的rate点理论上应该是null。

通过Prometheus接口计算rate(vm_search_delays_total{}60s) ，按照1分钟内聚合运算rate，返回的rate数据如下，在12:29:50时间点确实没有数据，那就是导致前面曲线缺失的原因了。

12:30:05 到12:30:50 的rate仍然是0，这是因为1分钟内聚合的rate计算中缺少第一个采样点数据，所以rate=0，符合Prometheus的rate计算原理。

# 聚合后的rate            

12:28:20 : 0            
12:28:35 : 0            
12:28:50 : 0            
12:29:05 : 0            
12:29:20 : 0            
12:29:35 : 0            
12:29:50 :        <- 缺少数据            
12:30:05 : 0            
12:30:20 : 0            
12:30:35 : 0            
12:30:50 : 0            
12:31:05 : 0            
12:31:20 : 0            
12:31:35 : 0

既然这样，那我们就将1分钟内聚合改成2分钟内聚合，就可以跨过缺少的采样点而避免rate是null的问题了。

将promQL改成 rate(vm_search_delays_total{}120s)后，可以看到12:30:05时间点的rate=315961170.1971519 了。

# 聚合后的rate            

12:28:20 : 0            
12:28:35 : 0            
12:28:50 : 0            
12:29:05 : 0            
12:29:20 : 0            
12:29:35 : 0            
12:29:50 : 0            
12:30:05 : 315961170.1971519            
12:30:20 : 315961170.1971519            
12:30:35 : 0            
12:30:50 : 0            
12:31:05 : 0            
12:31:20 : 0            
12:31:35 : 0

从图形上看，rate曲线也“正常”了。至于rate的值，从公式计算应该是：(31172047293 - 0) / 120，应该是259767060，而不是315961170.1971519，这种偏差是由于选择的时间范围和采样点有偏差，而Prometheus会根据采样点计算斜率来弥补这种点位偏差导致的，故这里可以忽略。

通过曲线图发现，其实真正有问题的节点是10，而不是3！

找到病灶 - 限流

正确的曲线图

再次通过pyroscope持续进行分析，对正常和异常时段进行比较：

• block duration：没有问题
• mutex duration：merge的锁占比较多（相对占比增加），但绝对值比较低。由于读写QPS占比发生了变化，所以并不能说明是merge的锁出现问题导致的。
• on-CPU火焰图：由于读写QPS占比变化，所以图中flush相关函数在火焰图中占比增加并不能说明问题。但是从其中一段函数top比对看，WaitIfNeed函数占比增加较为明显，通过查看这一段代码发现了问题。

on-CPU火焰图，flushPendingRows占比增多，但不明显

mutex duration，mergeWorker的占比明显增加，但是绝对值较小。

block duration， 比较起来也没有变化

然而比较正常与异常时段top函数，WaitIfNeed增加！

分析PaceLimiter及相关的代码发现，Victoria Metrics对任务做了优先级的区分，如果有高优先级任务存在，则低优先级任务需要等待。低优先级任务调用WaitIfNeed来检查是否需要等待。

这种实现并不合理：只要有一个高优先级任务在执行，其他所有低优先级任务都需要等待，写请求与合并任务属于高优先级任务，查询属于低优先级任务，所以只要有一个写入或者合并任务在执行，查询请求都必须等待，也就造成了查询延时增加。

所以之前从监控指标上来看，在cpu，磁盘等都没有成为瓶颈的情况下，查询请求QPS会偶发性抖动。

func (pl *PaceLimiter) WaitIfNeeded() {            
    if atomic.LoadInt32(&pl.n) <= 0 {            
        // Fast path - there is no need in lock.            
        return            
    }            
    // Slow path - wait until Dec is called.            
    pl.mu.Lock()            
    for atomic.LoadInt32(&pl.n) > 0 {            
        pl.delaysTotal++            
        pl.cond.Wait()            
    }            
    pl.mu.Unlock()            
}

结合之前的分析，所以可以得出结论：

节点13是SSD盘，其合并与写入等涉及到磁盘的操作更快，高优先级任务的执行也就更快，对查询请求的阻塞也更就短了，加上读盘速度更快，所以整个读取请求耗时更低，快速处理大量读取请求造成缓存过多的数据块，本身vm cache分片数较少，就造成了激烈的锁竞争。

而其极端的限流策略，更是导致资源分配完全偏向于写请求。

一个老难题 - 资源配额

看到这里，相信大伙都会觉得VM的限流太拉胯了，一点都不严谨。

那如果要你来实现这个限流，你该如何实现它？在改进这个限流之前，请先想好几个问题。

限流的阈值该如何设置？

要改进限流，第一个容易想到的就是加大读写并行度，就需要在有写请求的时候增加允许读的限流阈值。那么增加多少合理？还是自适应？但这种自适应可不像普通单向流量控制那么简单，这要控制读和写两个方向，而且真的是仅仅控制QPS而已吗？

流控是手段，隔离是本质！

读写QPS配额的比重能映射到IO吞吐上？如果一个读请求，读取几百兆或上千兆的字节，完全占满磁盘的吞吐怎么办？更何况写请求也需要读取数据，所以从QPS或者资源来控制都有各自的问题。

PaceLimiter设计目的就是保证高优先级任务需要的所有资源(主要是IO)都优先得到满足，而不是独占，还有空闲的资源，也可以分配给低优先级任务。那么需要对两种任务的资源进行隔离，而隔离的限制是弹性的。

所以，完美的实现应该是：当写请求需要资源时，优先分配；资源利用率没有达到100%时，余下资源可以分配给读请求。

切除阑尾 - 开发团队的做法

在现有技术下，要做到这种完美方案，几乎是不可能实现的，理论在工程上的实现就是一个取舍的过程。

是直接添加一个QPS读写配额，通过这种短平快的方式缓解问题，还是找相对更为合理的方案？就在我纠结时，发现开发团队在v1.86.2版本中，已经将限流这块逻辑全部都移除掉了，不再对任务做限制。那写请求很可能会被读请求影响，导致监控数据的写入丢失。

至于开发团队的决策，我们不得而知，如果是你，你会怎么做呢？