vivo Trace 监控追求极致的建设历程
作者：vivo 互联网服务器团队- Zhang Yi
当前 vivo 的应用监控产品 Vtrace 经常遇到用户反馈某个 Trace 链路信息没法给他们提供到实质的帮肋，对此团队一直在持续完善 JavaAgent 的采集。经过不断增加各类插件的支持，同时想方设法去补全链路信息，但一直还是无法让用户满意。面对这样的困境，需要改变思路，从用户角度思考，在产品中找灵感。同时产品重新思考在应用监控中一条完整的 Trace 应该展现给用户哪些信息？业界其它产品对 Trace 的监控可以观测到什么程度？带着这些问题，Vtrace 通过全面的同类产品对比分析，结合 vivo 实际情况自研 Profile 采集，从而开启涅槃之路。
专业术语
【Vtrace】：vivo 应用监控系统，是一款 vivo 自研应用性能监控产品。
【Trace】：通常用于表示一系列相关的操作或事件，这些操作或事件通常跨越多个组件或服务，一个 Trace 可能由多个 Span 组成。
【Span】：属于 Trace 中的一个小部分，表示某个特定操作的时间跨度，比如执行一次查询 SQL 的记录。
【APM】：APM 为 Application Performance Monitoring 的缩写，意为应用性能监控。
【POC】：通常指的是 "Proof of Concept"，即概念验证。在软件开发和信息技术领域，POC 是指为了验证某项技术、方法或想法的可行性而进行的实验或测试。在监控领域，一个监控 POC 通常指的是为了验证某个监控方案、工具或系统的可行性而进行的验证。
【Continuous Profiling】：持续剖析，有些厂商叫 Continuing Profile 或 Profiler，也有人将 Continuous Profiling 和 Trace、Metric、Log 放在同一位置。总之是一种持续性的性能分析技术，它可以实时监测和记录程序的性能数据，以便开发人员可以随时了解程序的性能状况。这种技术可以帮助开发人员发现程序中的性能瓶颈和优化机会，从而改进程序的性能。通过持续性地监测程序的性能数据，开发人员可以更好地了解程序的行为和性能特征，从而更好地优化程序的性能。本文中 Profile 一般指持续剖析。
一、背景
当前应用监控产品 Vtrace 中的 Trace 链路数据只串联了服务与服务，服务与组件之间的 Span 信息，但对于发生于服务内部方法具体执行耗时是无法监控的，即所谓监控盲区。
图 1
图 1 为当前 Vtrace 系统的一个 Trace 信息，这个 Trace 显示内部没有任何其它组件，事实上真的如此么？先看看下面实际代码：
从上面的代码可以看出接口/profile/test 的 profileTest 方法实际执行了四个私有方法：
doSleep()方法，让程序休眠 1 秒
synchronizedBlockBySelectMysql 方法查询 MySQL，但这个方法使用了 synchronized 修饰，多线程同时执行这个方法时会塞阻。另外查询 MYSQL 一般会使用连接池，这次测试的代码使用 Hikari 连接池
readFileAndToJson 方法读取文件数据并且将数据转 JSON 为 JSONArray
sendKafka 方法主要是发送数据到 Kafka
但这四个方法在 Vtrace 系统中的 Trace 信息中什么都体现不了，JavaAgent 并没有采集到相关信息。这恰好说明了这里存在监控盲区，并且盲区远比想象中的要大，某些场景中连最基本的 MySQL 执行的信息都看不到。
图 2
对于图 1 那种情况在实际中会经常遇到，用户会发现 Trace 中没有他想要的信息。有时会像图 2 中那样有几个组件的 Span，但整个 Trace 中依然存在一大片空白的地方，不知道具体的代码执行情况。
针对上述的场景，为了让用户通过 Trace 获取更多有用信息，后续需要做的有两件事：
支持对更多组件的埋点采集
针对 Trace 进行方法调用栈的采集
而本文主要从下面几个角度论述我们如何改变当前 Vtrace 的现状：
同类产品对比分析：通过 SkyWalking、DataDog 和 Dynatrace 三款产品的 Trace 观测程度对比分析，从产品的视角去获得 Vtrace 的优化思路。
程序设计：通过同类的产品功能引入行业中 Continuous Profiling 概念，结合同类产品的技术实现情况设计 Vtrace JavaAgent 对方法调用栈采集的技术方案。
压测分析：针对在 JavaAgent 增加方法调用栈采集之后进行压测，评估出 JavaAgent 改进后的资源影响，并且分析出资源消耗增加的根因与确定后续持续优化的方向。
落地评估：通过当前已经接入 Vtrace 产品的服务情况与 JavaAgent 压测结果去分析 Vtrace 的方法调用栈采集功能如何落地。
二、同类产品对比分析
在设计 JavaAgent 方法调用栈监控采集前，先看看业界的监控同类产品对 Trace 的分析能够做到何种程度。
下面我们使用 SkyWalking、DataDag 和 Dynatrace 三款同类产品，对上面/profile/test 接口进行监控分析。通过对同类产品监控情况的分析会给我们带来一些启发，同类产品的一些优秀设计思路也会有助于我们完善的 Vtrace 产品。
2.1 Apache SkyWalking
Apache SkyWalking 是一款优秀的开源应用性能监控产品，Vtrace 的 JavaAgent 就是基于早期的 SkyWalking 3.X 版本开发的。
图 3
上图为/profile/test 接口在 SkyWalking 的 trace 信息，显然可以看出请求中访问 MySQL 与 Kafka，其中 SQL 的执行时间大约为 2 秒（图 3 中的 MySQL/JDBC/PrepardStatement/execute 为实际执行 SQL 的 Span）。同时使用 Hikari 链接池工具获取数据库链接的信息也记录了，这个记录很有用，如果数据库链接池满了，一些线程可能一直在等待数据库链接池释放，在某些情况下很可能是用户数据库链接池配置少了。
相对于 Vtrace 系统的 trace 信息，显然 SkyWalking 观测能力强了不少，但依然存在 doSleep 与 readFileAndToJson 这两个方法没有观测到。
对于这种情况，想到了 SkyWalking 的性能剖析功能，那再利用性能剖析看看能不能分析出 doSleep 与 readFileAndToJson 这两个方法。
图 4
图 4 是 SkyWalking 对/profile/test 接口配置性能剖析的交互，这里可以配置端点名称、监控的持续时间，监控间隔以及采集的最大样本数。而监控间隔配置的越小采集到的数据会越精确，同时对服务端的性能影响则越大。
图 5
配置好性能剖析规则后，再次发出/profile/test 请求。等待了一段时间，从图 5 中可以看到 doSleep 和 synchronizedBlockBySelectMysql 方法的执行情况。
图 6
关于 synchronizedBlockBySelectMysql 方法的，如果是执行 sql 耗时，采集到的应该如图 6 左侧那样看到的是正在执行 SQL 的 socketRead0 方法，而这里显示的是 synchronizedBlockBySelectMysql 这个代码块，即性能剖析时 SkyWalking 采集到的数据方法栈的栈项为
synchronizedBlockBySelectMysql，这里由于 synchronized 的修饰在执行 SQL 前需要等待别的线程释放整个方法块。
从上述可以看出 SkyWalking 显然对 profileTest 方法能很有效地分析，但存在一个问题就是性能剖析不能自动持续分析，需要用户手动开启，遇到难以复现的情况时不好回溯分析。
虽然 SkyWalking 持续剖析存在这一点小瑕疵，但我们不得不承认 Skywalking 对 Trace 的分析还是挺强大的。Vtrace 的 JavaAgent 是在 SkyWalking3.X 版本的基础上实现的，而 SkyWalking 成为 Apache 项目后经过这几年的持续迭代已经发展到 10.X 版本了。对比我们 Vtrace JavaAgent，显然 SkyWalking 的进步巨大。
2.2 DataDog
与开源的 SkyWalking 不同，DataDog 是一款商用可观测软件，在 Gartner 可观测排名靠前。接下来我们使用 DataDog 去分析刚才的/profile/test 接口。
图 7
图 7 是使用 DataDog 采集到/profile/test 接口 Trace 数据，明显可以看出：
MySQL 组件与 Kafka 组件的执行耗时
整个 Trace 的 Safepoint 和 GC 占用时间
图 8
图 8 为本次 trace 的火焰图，从图中可以看到 readFileAndTojson 这个方法热点。
从 DataDog 的 Trace 信息中我们可以看出 DataDog 也能直接发现 MySQL 与 kafka 组件，同时提供这次 trace 的火焰图，从火焰图中能够看出 readFileAndTojson 方法执行。但 doSleep 方法与 synchronizedBlockBySelectMysql 方法关键字 synchronized 同步等待的时间没被观测到。
不过感觉到意外的是可以在 DataDog 中看到这次 trace 的 Safepoint 和 GC 占用时间，这样用户可以分析出该 Trace 是否受到 Safepoint 和 GC 影响。
2.3 Dynatrace
Dynatrace 也是一款商用可观测产品，Gartner 可观测排名常年第一，技术上遥遥领先。
图 9
图 9 为/profile/test 接口在 Dyantrace 中的一个 Trace 信息，图中左侧红框可以直接看到 MySQL 和 Kafka 组件，中间红框是这次 trace 的线程整体时间分布情况，包括 CPU 时间，Suspension 挂起时间，还有 Waiting、Locking、Disk I/O 和网络 I/O ，为了方便大家理解深层的性能特征他们用不同的颜色区分，具体说明如下：
表 1
从图 9 右边红色框框的可以看到这个 Trace 整个生命周期的线程各个阶段的分布，再点击“View method hotspots”，则本次 trace 的方法热点如下图图 10 所示：
图 10
看到图 10 的内容非常惊讶，源代码中的四个私有方法全部被观测到，四个方法底层的实质也显露出来，具体如下：
发现 doSleep 与 sendKafka 这两个方法，并且他们的操作主要是在 Waiting。
synchronizedBlockBySelectMysql 方法图中浅蓝色部分显示他在 Locking，等待着别的线程执行完 synchronized 修饰的方法；后半段粉色部分为查询 MySQL 的 IO 操作，细分为 Network I/O。
readFileAndToJson 方法中有一段紫色的部分 ，那是在读取文件的 IO 操作，分类为 Disk I/O，而同时读取文件与将文件中的内容转换为 JSON 也是这次 Trace 消耗 CPU 的主要代码。
上面除了整个 Trace 的方法热点的总览信息，还可以下钻进入每个方法再深度分析。
图 11
图 11 是展开 doSleep 与 sendKafka 两个 Waiting 方法分析，可以明显看出 doSleep 方法实际上底层耗费在 Thread.sleep，而 sendKafka 方法的 Waiting 是 Kafka 底层工具类 SystimeTime.waitObject 中执行更底层的 Object.wait。
图 12
图 12 为选定”Code execution“后再展开 readFileAndToJson 方法，这里两处主要耗费 CPU 的操作，一个是 JSON.parseArray，一个是 BufferedReader.readLine。
图 13
除了方法热点分析，Dynatrace 还提供了”Code level“的分析，从图 13 中可看到 Hikari 链接池的获取情况。
从结果上来看，Dynatrace 的观测能力果然遥遥领先，他的观测能力不是仅仅简单告诉用户每个地方的执行耗时，他告诉用户代码执行情况的同时让用户更好地了解程序每个行为的底层原理和性能特征。
2.4 分析总结
在完成上述三个产品的 Trace 分析后，结合当前 Vtrace 产品，做了一些对比：
表 2
通过同类产品对比分析发现当前 Vtrace 整体功能与业界领先的产品比较显得相对落后。另外，业界优秀的产品还有很多，而我们选择 SkyWalking、DataDog 和 Dynatrace 因为他们具有一定的典型性和代表性。而对于上述的三款产品，本文产品分析只是针对 Trace 链路的观测能力来测试来比较。
最初在考虑如何完善我们的 Trace 链路，我们的计划是参考新版 SkyWalking 的 Profile 功能，所以当时的同类产品分析只选 SkyWalking，而/profile/test 接口的四个私有方法也是提前就设计好的。
但在做设计评审时，发现只基于一个开源产品的能力去设计，最后可能得出的方案会是片面的。考虑到不同产品的 Trace 信息呈现会有所不同，于是我们决定再找一些同类的商用产品来对比分析。而同类产品 Trace 呈现出来的信息涉及数据采集，我们需要分析产品能力的同时也要去了解同行的采集技术方案。
因为曾经主导过一个可观测项目，邀请了国内外的主要 APM 厂商来企业内部私有化部署产品，用了长达半年多的时间对大概 10 款产品进行 POC 测试，大部分产品的 Trace 信息展示是差不多的，而当时很多产品的 Trace 观测能力并不比现在的 SkyWalking 会好。同时，简单看了当前一些国内大厂可观测产品 Trace 的交互后，为了避免同质化，便选择了当时 POC 没法私有化部署的 DataDog 与 POC 测试时效果远超同行的 Dynatrace。
由于/profile/test 接口的四个私有方法是在 SkyWalking 测试前就已经设计好的，所以在要把 DataDog 和 Dynatrace 加入测试时并不知道这两款产品会呈现出什么样的实际效果。现在都知道 DataDog 和 Dynatrace 的测试结果，这两个产品的 Trace 中都有出乎意料的重要信息，这带给我们不少启发。
本节最后说些题外话，相信国内很多大厂都有自己的可观测产品或者正在使用一些其它厂商可观测产品，你们可以将/profile/test 接口的代码用你们现在使用的监控产品测试一下，看看你们的 Trace 能观测到什么，如果有一些意外的发现，不防联系我们，大家一起相互学习学习。
三、程序设计
通过同类产品的对比分析，为了让我们的 Trace 信息更完整，第一件事是需要完善组件。同时同类产品可以观测到更多有用的信息，所以第二件事我们需要知道这些信息同类产品是如何采集的。另外也不能只顾着单一完善 Trace 信息而设计 ，设计上需要考虑后续的整体规划。
随着对同类产品的深入了解知道同类产品使用了一种叫 Continuous Profiling 技术手段，通过这种手段他们才有如此丰富 Trace 信息。比如 DataDog 的火焰图和 Dynatrace 的方法热点正是这技术手段的体现。同时在他们产品中 Continuous Profiling 有明确的定位，常见有下面四个功能：
CPU Profiling：深入了解进程的方法热点，按代码执行、网络 I/O、磁盘 I/O、锁定时间和等待时间分解和过滤数据，常见的火焰图正是 CPU Profiling 的产品体现。
Memory Profiling：内存分析可以了解应用程序随时间变化的内存分配和垃圾回收行为，识别分配了最多内存的上下文中的方法调用，并将此信息与分配的对象数量相结合。
Memory Dump Aalysis：通过进程的内存使用进行 dump 并分析。
Continuous Thread Analysis：对线程持续分析，主要是后台线程组，记录每个线程各个时间段的线程状态以及资源使用情况。
不难看出上述功能在很多同类产品都有，比如 Vtrace 现在利用 Vivo 运维工具实现了 CPU Profiling、Memory Profiling 以及 Memory Dump Analysis。但是 Vtrace 的 CPU Profiling 与 Memory Profiling 并不是持续的，需要用户手动触发，每次最多只能剖析 5 分钟。后续我们会慢慢实现或优化 Continuous Profiling 的各个功能，而现在 Vtrace 系统是借助 CPU Profiling 的技术手段去完善每个 Trace 的方法调用栈信息。
3.1 方案选择
在分析 SkyWalking、DataDog 和 Dynatrace 是如何实现他们的 Profile 信息采集前，我们先看看 Java 应用在业界主流实现 CPU profling 的技术方案：JMX 、JFR 和 JVMTI AsyncGetCallTrace。
（1）JMX
Java Management Extensions（JMX）是 Java 平台上的一种管理和监控技术，它允许开发人员在运行时监视和管理 Java 应用程序，一般使用 ThreadMXBean 中的 dumpAllThreads 可以获取当前线程执行的方法栈情况，利用每次获得的线程调用栈栈帧信息，可以实现方法热点的监测。
（2）JFR
Java Flight Recorder（JFR）是 Java 平台上的一种性能监控和故障诊断工具，JFR 的特点包括低性能开销、低停顿、持续监控、动态配置和丰富的数据。它可以在应用程序运行时收集性能数据，而几乎不会对应用程序的性能产生影响。但 JFR 的支持对 Java 版本有一定的要求。
（3） JVMTI AsyncGetCallTrace
AsyncGetCallTrace 是 JVMTI 中的一个非标函数，用于异步获取线程的调用堆栈信息。使用 AsyncGetCallTrace，开发人员可以在应用程序运行时异步去获取线程的调用堆栈信息，且不会阻塞线程的执行。这对于性能分析和故障诊断非常有用，因为它允许开发人员在不影响应用程序性能的情况下获取线程的调用堆栈信息，从而更好地了解应用程序的执行情况和性能特征。
上述三种方案便是实现 CPU Profiling 的主流方案，这三个方案在我们之前分析的三个产品中使用情况如下：
表 3
SkyWalking 使用 JMX 实现性能剖析。他的实现是通过将采集到的 Trace 在 JVM 内部开启线程任务，线程任务通过 segmentId 绑定当前 segmentId 所在的线程，按照采集频率定时使用 getStackTrace 获取各个时段的调用栈信息。但它的设计并不是为了实现 CPU Profiling，他只是一个补全 Trace 的链路分析快速实现，针对一些已知问题，常复现的问题，可以快速定位到根因。后续 SkyWalking 也不一定会使用上述三种方法实现 Java 语言的 CPU profling。
DataDog 最开始是用 JFR 实现 CPU Profiling，后来结合开源工具 Async-profiler，完善整个 Continuous Profiling 功能。Async-profiler 实现完全基于 JVMTI，其中它的 CPU 热力图就是得益于 AsyncGetCallTrace 接口。
Dynatrace 是个异类，它做分布式 Trace 链路监控的时候，谷歌 Dapper 论文还要几年才出世，谷歌 Dapper 流行后，它已放弃了通过“-javaagent”指令的方式实现字节码增强，在 java，.net，go，python 等众多语言实现无需引用相应的 agent 即可深入监控代码级别的内部链路。它早期使用 JavaAgent 实现的产品 AppMon 可能使用过 JMX 实现 CPU Profiling，10 年前它改版后便完全基于 JVMTI 的 AsyncGetCallTrace 实现。
基于 JFR 或 AsyncGetCallTrace 实现 CPU Profiling 性能开销会低很多。我们 vivo 的每个人都追求极致的性能，在技术选型上更偏向性能好的方案。而从厂商 DataDog 已经从 JFR 转向通过结合 Async-profile 来实现整个 Continuous Profiling，JFR 可能并不是一个好选择，所以剩下 AsyncGetCallTrace 的实现方式。或许最终我们也会利用 Async-profiler。
但是无论利用 Async-profiler 或者像 Dynatrace 一样独自去实现基于 AsyncGetCallTrace 采集，这对于我们监控团队来说都存在困难，因为我们团队缺少这方面的人力储备。如果我们选择基于 AsyncGetCallTrace 实现，要从零开始，需要学习 c++与 Async-profiler。这样整个研发周期会被拉得很长，短则至少三个月长则半年，同时有较大的不确定性，交付存在风险。
另外基于 JMX 实现的采集方案被认为性能不够好，但真正的性能损耗情况需要实践去检验。如果 10ms 和 20ms 的采集频率消耗资源太高，可以尝试降低采集频率。为了快速解决用户痛点，现阶段我们先选择基于 JMX 在 Vtrace 的 JavaAgent 中实现，在 JavaAgent 中实现后再基于压测情况决定后续落地方案。
3.2 基于 JMX Profile 采集设计
图 14
事实上我们这次的设计并不是为了实现 CPU Profiling，更多是为了补全 Trace 的信息。而对 Trace 的方法堆调用栈情况采集，我们基于 JMX Profile 设计如下：
1、JavaAgent 启动时，如图 14 所示开启一个采集频率 50ms Profile 采集线程，当然这里采集频率用户是可以自行配置的。
2、Trace 进入时将 traceId 与当前 trace 线程 id 合并成一个 traceSegmentId(基于 SkyWalking 6 以上实现的 JavaAgent 可以直接使用他们自身的 traceSegmentId)，同时将这 traceSegmentId 与当前线程 Id 绑定放到一个叫 TRACE_PROFILE_MAP(Map)的集合中。TRACE_PROFILE_MAP 除了记录 traceSegmentId 和线程 id，同时会记录后续被 Profile 线程采集到的快照。
3、Profile 数据采集的线程会定时将 TRACE_PROFILE_MAP 集合当前的所有线程 id 通过 ThreadMXBean.getThreadInfo 获得每个线程当前栈帧信息。记录当前栈帧顶部信息并按照我们设置的深度保留栈帧的一些信息当作本次快照。如果这个 trace 线程下一次被采集的栈帧顶部信息与栈深度与这次一样，我们不需要记录本次快照，只需将上次快照出现的次数+1，如图 14 中栈顶为 Thread.sleep 的快照被我们记录了 4 次。如果相邻的两次采集栈帧顶部信息不一样，我们则记录两次快照信息，如图 14 对于这个 trace 我们最后记录了栈顶为 Object.wait 的快照 3 次。
4、trace 结束时，先根据 traceSegmentId 获取到本次 trace 采集到的 Profile 快照数据，然后交给后续 Profile 数据上报线程异步处理，同时将 TRACE_PROFILE 集合记录当前 trace 线程的相关数据从集合中移除。
5、如果这个 trace 是使用到多线程会整个 trace 会多个不同的 traceSegmentId，每个异步线程的相关 Profile 数据也会被采集到。
从流程上来看，基于 JMX 实现 CPU profiling 采集确实简单，但也可以看出定时采样的方式本身的缺陷，如图 11 中 readFileToJson 方法中显示的采集频率太大两次采样会中间的读取文件的 Disk I/O 会被忽略，但这也是无法避免的，用其它技术方案来实现也一样会有这种问题。因此在实现 Profile 采集后，后续需要测试不同场景下不用采集频率对资源的利用情况，然后结合当前 vivo 服务的整体情况，再最终决定这个方案是否用于生产。
3.3 基于 AsyncGetCallTrace Profile 采集设计
虽然我们先尝试基于 JMX 的方式实现 Profile 采集，但不妨碍我们探讨别的实现方案，很可能后续团队能力起来后再转向基于 AsyncGetCallTrace 实现。
通过分析 AsyncGetCallTrace 源码与 Async-Profiler 的实现，发现基于 AsyncGetCallTrace Profile 的采集流程和上述流程相差不大，无非就是怎么触发采集，在 Liunx 系统一般使用信号量来触发，这也会大大地降低采集时的性能损耗。
有些操作系统不支持使用信号量来调用 AsyncGetCallTrace 函数，可能需要用 c++实现一个不受 JVM 管理的线程，避免采集时受 JVM SavePiont 或 GC 的影响。
另外并不是所有操作系统的 JVM 中都提供 AsyncGetCallTrace 这个函数。
上述基于 AsyncGetCallTrace 的采集设计只是通过简单的一些了解而设想的，并不一定正确，欢迎指正。
后续如果我们完全实现了基于 AsyncGetCallTrace Profile 采集我们再向大家介绍实现的细节。
3.4 存储设计
介绍了 Profile 数据的采集设计，接下来聊一下存储设计。
一个时间跨度为 1 秒的 Trace，在采集频率为 50ms 时最多可能会被采集到 10 个副本。假设 Profile 采集记录 stack 深度为 20，一份快照信息大约 1KB，这样的话每个 Trace 最多可能需要增加 10KB 的存储。如果记录 stack 深度为 100 时快照信息大小则 6KB 左右。
图 15
上图为我们 Prfoile 采集的一个快照文本内容，这个数据大约 1kb。如果每个快照数据都这样存储，则会占用大量的存储。同一个接口不同 Trace 的 Profile 数据会存在大量相同的快照文本，相同的快照文本用同一个 UID 来保存。UID 可以为快照文体的 MD5 值，每个 UID 只占 16 字节。后续在分析 Trace 信息时再将 UID 对应快照文本显示给用户，这样会节省大量的存储成本 。
图 16
图 16 为 Vtrace 基于 JMX 实现 Profile 采集到数据，为了快速验采集的效果直接让采集到的快照数据作为 Span 存储。图中第一行数据为整个请求的 trace 耗时，而红色框中的则为这个在 trace 我们 Profile 采集线程采集到的调用栈信息，从结果来看把我们原先的一些监控盲区补上来了。这图的数据只是临时处理，实际后续产品交互并不会这样展示。
现在存在的问题就是 Vtrace JavaAgent 对所有 Trace 采集会整个服务的性能有哪些影响，而这些影响，是否在我们的接受范围内。我们需要对增加 Profile 采集后对 JavaAgent 进行压力测试，需要对比开启 Profile 采集与未开启 Profile 采集的性能指标差异。
四、压测分析
4.1 测试设计
测试时需要考虑很多因素，因此在测试前先对测试做好设计，有以下的测试要点：
测试需要考虑环境，比如 cpu 核心数，容器或虚机，有条件最好使用物理机测试
测试考虑不同采集频率时对性能的影响
需要在不同 TPS 的情况下对比资源的消耗
要考虑同一 TPS 下，IO 不同的密集程度下资源消耗差异
4.2 测试结果
测试的时候我们记录了很多指标，有很多数据，本文中就不一一展示了。Vtrace 的 Profile 采集对应用性能的产生实质影响在这里我们只需考虑 CPU 使用和 GC 情况，因为采集增加的内存会侧面反映在 GC 情况中。
下面为不同场景下开启与不开启 Profile 持续剖析时的资源利用情况对比：
表 4
上述场景中 TPS 小于等 50 时，GC 次数很少，开启 Profile 采集对 GC 的影响相差不多。而开启 Profile 采集后对内存的影响主机体现在 GC 上。
场景 1 与场景 2、场景 3 与场景 4、场景 5 与场景 6 三组采集频率不同的对比测试，可以看出 Profile 采集频率直接影响服务的资源消耗。
随着测试 TPS 的上升，Profile 采集消耗的资源也相应的增加，1000 TPS 内，从容器与虚机，CPU 4 核心时，开启 Profile 采集 CPU 消耗整体增加不高于 5%; CPU 2 核心时 100 TPS 内开启 Profile 采集 CPU 消耗整体增加不高于 4%。
对于这个结果并不能说很理想，但又比预期要好一些，后续我们再结合我们当前应用的情况再分析是我们基于 JMX 实现的 Profile 是否可以投入生产使用。
而从上面的性能压测结果可以看出通过降低采集频率，CPU 资源消耗有明显减少。但采集频率不宜过低，50ms 对于大部分应用来说可以采集到很多有效的信息，这是我们的一个推荐值。
4.3 资源消耗增加原因
在压力测试后我们知道开启 Profile 采集后 CPU 资源会有所增加，接下来需要确定导致资源消耗增加的地方有哪些。
为了找出根因，最初我们想使用 Arthas 来生成火焰图来分析，虽然这个场景应该也能分析出根因，但并不是很直观，分析过程不会很流畅。Arthas 分析这个场景大概是这样的，在开启 Profile 采集前后分别生成火焰图，但这样没法直观地去对比出开启采集后额外增量的热点。同样针对线程分析，Arthas 并没有将线程归类分组，显示了大量的 http-nio-?-exec 线程(?为线程 ID)。后来我们再次想起了前提到的 Dynatrace 中的 Cpu Profiling 与 Continuous thread analysis 功能，后续可能我们也会去实现类似的功能，抱着学习下商业化产品的 Continuous thread analysis 功能，于是便使用 Dynatrace 来分析。
虽然这个场景可以直接使用 Dynatrace 的方法热点分析，但从进程到线程对比开启 Profile 采集前后指标，整个流程会更加顺畅，同时这样的排查思路与产品呈现会带来一些设计上的启发。
图 17
图 17 是流量相同的情况下，开启 Profile 采集前后指标的变化，从中可以看出：
整个 java 进程 CPU 变化从 8.51%增加到 12%
后台线程 CPU 变化从 4.81%增加到 8.4%
GC 线程 CPU 变化从 0.15%增加 0.3%
上述结论我们知道开启采集后导致进程 CPU 使用率增加的主要有后台线程和 GC 线程，GC 线程略有增加主要还是采集时额外使用的内存增加导致，所以下面我们重点对后台线程分析，这里用到的便是 Continuous thread analysis 功能。
图 18
图 18 为开启 Profile 采集后的后台线程分析，展示了某段时间内主要所有后台线程组的运行情况，我们可以看出增加的两个进程组正好是我们的 Profile 采集线程与 Profile 数据发送线程，而 Profile 采集线程的奉献度占比远大于 Profile 数据发送线程。
图 19
针对 Profile 采集线程我们再深入这个线程一段时间内的方法热点去看，从图 19 的结果上看 Profile 采集线程消耗 CPU 主要在调用 JVMTI 方法(ThreadImpl.getThreadInfo1)获取当前线程的信息。
对这个判断有点怀疑，认为线程信息采集到后处理调用栈的逻辑会有所消耗资源。对这个疑问，简单的方法可以先将 Profile 采集线程中调用 ThreadImpl.getThreadInfo1 方法之后的所有代码注释然后压力测试。接着加上线程栈数据处理的代码同时注释 Profile 采集发送的代码，然后再在同样的条件下压测，之后再对比两次压测的性能差异。当然也可以使用 Arthas 来生成火焰图分析，但我们并不是这样做的，明显有更加直观的办法，可以看看下面的 Profile 采集伪代码：
通过上述代码测试后发现第 4 步的代码确实上也会有一些消耗，但几乎 99%以上都是消耗在第 2 步中。而 Dynatrace 显示 ThreadImpl.getThreadInfo1 占比为 100%，这是因为 Dynatrace 的 Profiiling 功能一样也是有采样频率的，只是时间段内采集到的样本全部显示 Profile 采集线程获得 CPU 时间片的方法是 ThreadImpl.getThreadInfo1，而这个测试恰好印证了 Dynatrace 方法热点的准确性。
而对于 JMX 中的 ThreadImpl.getThreadInfo1，这是一个 native 方法，是无法直接优化的，只能等后续我们有能力基于 AsyncGetCallTrace 去实现 Profile 采集再解决。
4.4 压测小结
通过本次压力测试，我们清楚了基于 JMX 实现的 Profile 采集的性能消耗大致情况，也知道了性能瓶颈在哪里以及后续的优化方向。
五、落地评估
接下来我们需要分析当前接入 Vtrace 产品 vivo 服务的情况，后面基于上面的测试结果与现状去评估我们 Profile 采集能否最终落地。
5.1 当前 vivo 服务情况
目前接入 Vtrace 的 2500+个服务中有 200 多个服务他们实例的平均 TPS 大于 100 ，而单实例平均 TPS 小于 100 的服务占 91.2%。下面表格中的数据是基于工作日某一分钟统计得出的当前 Vtrace 所有服务实例平均 TPS 值的分布情况：
表 5
5.2 落地分析
通过上表可以看出 vivo 当前服务的情况，我们之前的测试结果表明在 2c4g 和 4c8g 的机器上服务 TPS 为 20 时 Profile 采集频率设置 50ms，cpu 消耗增加 1%不到。而我们约 75%的服务 TPS 小于 20，也就是说这些服务如果愿意接受 1%的 CPU 资源消耗，基于 JMX 的 Profile 采集也能服务到大量的用户。
对于 TPS 大于 100 的服务，如果只是某些固定接口需要排查，可以通过配置对需要 Profile 采集的接口进行过滤，这样可以扩大落地的范围。
因为考虑压力测试的测试场景覆盖场景有限，我们会更谨慎一些，先完善一下 Profile 采集保护机制，后面一些服务中试点再逐步铺开。如果 TPS 小于 20 的服务顺利展开，之后再考虑覆盖 TPS 在 20 以上到 100 之间的服务。TPS 超 100 的服务可以针对需要分析的接口开启 Profile 采集。至于所有服务全量采集覆盖可能需要等于我们攻克基于 AsyncGetCallTrace 的采集设计之后。
很多大型企业可能和 vivo 差不多，大部分 90%以上的服务单个实例 TPS 在 100 之内。而传统企业 TPS 小于 100 的占比则更高，如果是制造业的话可能 90%的服务 TPS 不到 20。不过很多企业部署方式与 vivo 不同，他们可能在一个 8c16g 的机器上部署好几个服务实例，这样的话每个实例增加 1%的资源消耗对于单个机器可能就显得多了。还好 vivo 基本上都是单机单实例部署或者容器部署，所以避免了上服务混合部署的情况。
最后，我们基于 JMX 的 Profile 设计虽然不是业界内的最优解，但却是当前快速解决 vivo Vtrace 监控的一个痛点的最优解。
六、未来展望
面对着困境我们努力优化却回报不高，在同类产品的分析后我们探索出改进方向，而在技术选型上我们做了一些妥协，最后随着对压测结果与 vivo 的实际情况分析发现我们还算交了一份不错的答卷。
图 20
上图展示了 Profile 采集的最终效果，与图 1 相比，我们取得了巨大的进步。在优化了 MySQL 与 Kafka 的插件支持后，我们再次将 Vtrace 与同类产品进行对比：
表 6
重新对比，可以看出 Vtrace 的 Trace 分析能力有了显著的变化，从最初无法识别基本组件，提升到与头部同类产品不相上下。这样的 Trace 分析能力在国内可观测领域属于顶尖水准，全球范围内也达到一流水平。
后续我们会重新整体去规划 Continuous Profiling 的相关设计，同时团队慢慢学习提升技术让团队能够基于 AsyncGetCallTrace 将 Profile 采集的性能优化到最低。这并不只是为了优化 Profile 采集的性能，而是考虑到实现整个 Continuous Profiling 团队也必须提升相关的技术能力。强大齐全的 Continuous Profiling 能力可观测系统根因分析的关键，采集端消耗资源越小观测能力的上限才会越高。
涅槃之路已经开启，涅槃之路就在脚下，但这也只是刚刚开始。未来 Vtrace 不需要用户配置任何的检测规则，服务出现异常时 Vtrace 能够自动检测出问题。自动检测出来的问题会自动定位出异常的的根因及异常影响业务的范围，比如受到影响的接口上下文、接口请求量与用户数量。而告警通知用户可以按照自己的团队要求去分派告警或者按照个人需求去订阅告警，告警按照着每个团队或个人的喜好方式流转。
版权声明: 本文为 InfoQ 作者【vivo互联网技术】的原创文章。
原文链接:【http://xie.infoq.cn/article/db66a02e4c44b12893856a6f7】。文章转载请联系作者。
官方公众号：vivo互联网技术，ID：vivoVMIC 2020-07-10 加入
分享 vivo 互联网技术干货与沙龙活动，推荐最新行业动态与热门会议。
评论