lprof：用于分布式系统的非侵入式请求流剖析器 - 《Apaas平台》

论文地址：lprof：用于分布式系统的非侵入式请求流剖析器-Zhao等人。2014年

The Mystery Machine需要日志记录中的请求id，该id可用于关联跟踪中的条目。如果你没有呢？lprof绝对充分利用了系统已有的所有日志记录。

lprof的新颖之处在于：

（i）它不需要插入或修改源代码，而是从正常系统操作过程中输出的日志中提取信息；
（ii）它能够从日志中自动识别每个请求并分析其性能行为。具体来说，lprof能够在调用方法、使用帮助线程和调用其他节点上的远程服务时重建每个服务请求的处理方式。

作为评估的一部分，lprof与HDFS、Hadoop-YARN、Cassandra和HBase中的现有日志一起使用，处于默认日志级别。平均而言，它能够在88%的时间内准确地将日志记录与单个请求的处理关联起来。

为了评估lprof在调试实际异常方面是否有效，我们从与我们测试的系统相关联的bugzilla数据库中随机选择了23个用户报告的实际性能异常。这使我们能够通过少量的示例了解lprof可以使实际性能bug受益的百分比。对于每个bug，我们都会仔细阅读bug报告、讨论以及相关的代码和补丁来理解它。然后，我们复制每一个获得日志，并应用lprof分析其有效性。这是一个非常耗时的过程…

lprof在检测和诊断这些问题中有2/3是有用的。对于一个需要对源代码进行零修改的工具来说，这是一个非常令人印象深刻的结果。

基本问题都是非常熟为人知的：

…很难理解这些系统的性能行为，因为服务

（i）分布在多个节点上，
（ii）由多个子系统（如前端、应用程序、缓存和数据库服务）组成，以及
（iii）由多个线程/进程以高并发度运行来实现。

与The Mystery Machine一样，作者观察到分布式系统倾向于输出大量的日志语句。“在本文中，我们显示日志中的信息足够丰富，可以恢复分散的和混合的日志输出消息的固有结构，从而支持像lprof这样有用的性能探查器。”

当您不得不处理任何可用的内容时，从日志中找出每个请求的信息是一个非常重要的问题：日志消息是非结构化文本，它们分布在系统中的多个节点上，并且来自多个请求和线程的消息相互缠绕。

lprof实现与Java一起工作，并使用静态字节码分析尽可能多地从日志消息中推断。对于HDFS、Yarn、Cassandra和HBase代码基，分析大约需要2分钟。静态分析分四步进行：

首先，分析代码中找到的每个日志打印语句。它将由字符串常量和变量插入组成。将生成一个正则表达式，该表达式将与语句生成的日志消息相匹配（例如：接收块BP-（.）：blk\u（.）\ u.*）。生成正则表达式需要追溯到插入的toString（）实现。如果插入的类型可以重载，并且子类型具有不同的toString（）实现，则会创建多个regex。regex用于将日志消息映射到可能已输出消息的代码中的日志点。
其次，对于日志语句中包含的变量，使用数据流分析来确定哪些变量被修改，哪些变量没有被修改。未修改的是候选请求标识符。

请求标识符用于从不同的请求中分离消息；也就是说，具有不同请求标识符的两个日志消息被保证属于不同的请求。然而，相反的情况并非如此：具有相同标识符值的两条消息可能仍然属于不同的请求…。为了推断哪些日志点属于同一请求的处理，还通过分析修改标识符的时间来标识顶级方法。我们使用术语top-level method来指代专门处理单一类型请求的任何线程的第一个方法。

第三，在每个请求没有唯一id的情况下，使用时间顺序分析来提供帮助。例如，如果日志消息A必须在代码块分析的日志消息B之前，那么如果日志包含序列B，A，我们知道这些必须是不同请求的记录。这不仅仅是单个方法中的代码，还考虑了整个调用图的DAG：
…lprof从方法的调用图和控制流图（CFG）为每个顶级方法（在上一步中标识）生成一个有向无环图（DAG）。此DAG包含可从顶级方法访问的每个日志点，用于帮助将日志消息属性设置为顶级方法。

最后，通信对分析用于识别相互通信的线程。这可以识别同一进程中通过线程或共享内存通信的线程。它还着眼于网络上的通信：

具体来说，每当lprof找到一对invoke指令，其目标方法分别是来自同一类的序列化和反序列化方法时，包含这两条指令的顶级方法就会配对。开发人员经常使用第三方数据序列化库，如Google协议缓冲区。这进一步简化了lprof的分析，因为它们提供了标准化的序列化/反序列化api。在我们评估的系统中，Cassandra是唯一一个不使用Google协议缓冲区，但实现自己的序列化库的系统。对于Cassandra来说，一个简单的注释可以将C.serialize（）和C.deserialize（）配对到任何C类中，这就足以正确地对所有正在通信的顶级方法进行配对。lprof还解析Google Protocol Buffer的协议注释文件，以标识RPC对，其中显式声明每个RPC。

在静态分析阶段结束时，lprof输出一个表示系统日志打印行为的文件。它由以下四部分组成：

顶级方法：一个元组列表，其中

（i）顶级方法的名称，
（ii）记录点的DAG表示的索引，以及
（iii）请求标识符列表；

DAGs：每个顶级方法的DAG；

日志点regex：每个日志点的正则表达式和每个通配符的标识符；
通信对：一个元组列表，用于标识通信点以及所通信数据的标识符。

此文件还包含一些索引以加快处理速度。它被发送到集群中要处理日志的每台计算机。

与其他系统不同的是，lprof先对记录进行采样，然后将其发送到一个中心位置进行处理，lprof首先对日志记录进行原位处理。整个日志处理具有map reduce计算的形式：

lprof的MapReduce日志处理作业中的Map函数首先将来自同一请求的打印日志消息缝合在存储日志的同一节点上，这只需要对每个日志文件进行一次线性扫描。只有来自日志文件的摘要信息和来自遍历多个节点的请求的摘要信息才会在洗牌阶段通过网络发送到reduce函数。这个
避免通过网络将日志发送到一个集中的位置来执行分析，这在真实的集群中是不现实的。

map和reduce函数使用称为请求累加器（RA）的通用数据结构，该数据结构收集与同一请求相关的信息：

每个RA包含：（i）分组到该RA中的顶级方法的向量；（ii）每个请求标识符的值；（iii）日志点序列的向量，其中每个序列来自一个顶级方法；（iv）遍历的节点列表，具有最早和最晚的时间戳。map和reduce函数将迭代地将来自同一请求的日志消息信息累积到RAs中。最后，每个请求将有一个RA，其中包含从其所有日志消息汇总的信息。

在初始扫描期间，如果顶级方法匹配，标识符值不冲突，并且日志点与DAG中的时间序列匹配，则将解析的日志条目添加到现有RA。否则，将创建新的RA。然后在还原阶段之前将结果进行局部合并。

如果这两个RAs中的两个顶级方法之间存在通信对，并且请求标识符值不冲突，那么它将两个RAs合并为一个RAs。此外，作为一种启发式方法，如果RAs的时间戳之间的差异大于用户可配置的阈值，则不合并RAs。

然后为每个RA分配洗牌key，为还原阶段做准备：

我们通过考虑通信对来实现这一点。在静态分析的最后，如果存在连接两个顶级方法a和B的通信对，则a和B连接在一起成为一个连接组件（CC）。我们迭代地将更多顶级方法合并到这个CC中，只要它们与这个CC中的任何顶级方法进行通信。最后，CC中的所有顶级方法都可以通信，并且它们的RAs被分配了相同的shuffle密钥。

如果通信的顶级方法具有公共请求标识符，则这些标识符用于进一步区分随机密钥。如果一个RA不能与另一个RA通信，那么就不会发生进一步的洗牌，而是直接输出到数据库。在reduce阶段结束时，来自每个RA的信息存储到数据库表中。最终输出大小约为原始日志大小的5%。

数据库中的每一行代表一个单独的请求，并与一个日志序列id（LID）相关联。日志序列id是请求的日志点序列（例如LP1、LP3、LP4、LP9，…）的哈希。

注意，LID捕获日志消息的唯一类型和数量、它们在线程中的顺序以及线程的数量。但是，它不保留线程之间的计时顺序。因此，在实际应用中，并不存在许多唯一的日志序列；例如，在HDFS中，200个EC2节点上只有220个唯一的日志序列在24小时内运行各种作业。我们还生成一个单独的表，将每个日志序列ID映射到日志点序列，以启用源代码级调试。

web应用程序可以可视化lprof的分析结果。最后介绍了抽样：

我们遇到的一个挑战是，当可视化请求的延迟时，请求的数量太大。因此，当查询结果中的请求数大于阈值时，我们执行向下采样并返回较小的请求数。我们使用了最大三角形采样算法，它首先将整个时间序列数据分成小块，然后在每个小块中对覆盖最大区域的三个点进行采样。为了进一步隐藏采样延迟，我们将所有请求预采样为不同的分辨率。每当服务器接收到用户查询时，它会并行检查每个预采样分辨率，并返回其数据点数量低于阈值的最高分辨率。

作者的结论是：

lprof能够将分散和交织的日志消息缝合在一起，并根据对系统代码进行离线静态分析的信息将它们与特定的请求相关联。我们的评估表明，lprof能够准确地对来自广泛使用的、生产质量高的分布式系统的88%的日志消息进行属性化，并且有助于调试65%的抽样实际性能异常。