7.3　埋点和输出日志

实现分布式服务跟踪系统的主要思路是通过服务调用链各服务处理节点生成相应的日志信息，通过同一请求中生成的日志具有同一个ID将不同系统或服务“孤立的”日志串在一起，重组还原出更多有价值的信息。

也就是说，在每一个URL请求都会生成一个全局唯一的ID，鹰眼平台中称为TraceID，这个ID会出现在该请求中所有服务调用、数据库、缓存、消息服务访问时生成的所有日志中。因为上述所有的资源访问均是在分布式环境下进行的，如何将该TraceID平滑地传递到各个服务节点上呢？如果要求应用程序中实现服务链路日志的打印和TraceID的传递，则在程序中有大量的日志打印代码，而且需要将TraceID采用业务数据的方式传递给下一服务节点，这些都给应用带来了非常大的代码侵入。

因为阿里巴巴的大部分应用均使用Java语言编写，而且统一通过上文提到的HSF服务框架进行通信，其他如分布式数据库、消息服务、缓存服务等中间件平台在集团层面都进行了很好的统一标准化，所以阿里巴巴采用了另外一种方式，将实现服务调用、各种资源的访问所需要生成服务链路日志，以及TraceID传递等功能的代码（称为埋点）植入到了服务框架层和各资源的访问驱动层，也就是在中间件层面上统一实现了鹰眼的上下文创建以及日志埋点功能，让调用上下文在中间件的网络请求中传递，同时将调用上下文信息保存在了本地ThreadLocal中，从而实现了鹰眼平台所需的调用上下文和日志信息对于应用开发人员完全透明。

图7-6示意了一次请求产生埋点日志信息的流程图，“start Trace”为这次请求产生了上下文信息，即TraceID。关于TraceID的生成规则，可以根据业务的需要在TraceID中包含一定的业务信息，比如前端应用的IP地址，这样可以通过该信息快速定位到生成此次请求的前端应用；比如创建时间，方便后期将修改日志信息按照时间维度进行分区存储。在淘宝的环境中，TraceID一般会包含以下信息：

·IP地址：在淘宝环境可直接映射到前端应用。

·创建时间：在存储时用于分区。

·顺序数：用于链路采样。

除了TraceID负责将URL请求中所有的服务调用和资源访问关系串联在了一起，还有另外一个ID在分布式服务调用过程中也起到非常重要的作用，这个ID就是RCPID，用于标识日志埋点顺序和服务调用间的嵌套关系。

在实际的业务场景中，服务的调用一定会有顺序性，比如在订单中的金额没有计算完成时，是无法创建支付记录的；也会有服务的嵌套、同步、异步调用，比如订单创建服务中会调用支付中心的接口进行支付记录的创建。通过消息服务的方式，让好几个服务同时执行计算处理，形成了一对多的服务调用，也就是会形成类似树型的服务调用关系。面对这些多样的服务调用场景，如何清晰、准确地记录下各种场景下服务调用间的关系，RCPID的生成方式变得比较重要。

图7-6　一次服务请求产生埋点日志流程图

在鹰眼平台中，是通过顺序编号的方式表示服务间的顺序关系，采用如1.1、1.2.1的多级编号方式体现出服务的嵌套和调用关系，以商品订单创建为例（如图7-7所示），图中的数字即为RCPID的示意，鹰眼平台正是通过RCPID还原出一次请求过程中各服务间的调用关系。

在图7-7中的“服务调用”过程中，都会将在前端应用中生成的TraceID和RCPID传递到后端应用1和2的应用实例中，让应用实例在打印埋点日志时能包含这些调用上下文信息，为随后鹰眼服务器通过日志里的这些上下文关键信息获取到同一URL请求引发的一系列服务调用和资源访问，以及这些服务调用的顺序和关系。

埋点日志信息会用于各种不同的分析、统计、监控等场景，除了上文提到的TraceID和RCPID是一定会保存在埋点日志中之外，还需要有其他更多的信息来满足业务对鹰眼监控平台的需求。从鹰眼监控平台多年的发展来看，埋点日志中会包含以下信息。

图7-7　订单创建场景下RCPID标示示意

·TraceID、RPCID、开始时间、调用类型、对端IP。

·处理耗时。

·处理结果（ResultCode）。

·数据传输量：请求大小/响应大小。