分布式链路跟踪服务属于写操作频繁而读操作相对较少的服务类型，它在我们进行线上问题排查时发挥着重要的支撑作用。我曾参与过一个系统，该系统同时为多条业务线提供支持，实际使用的服务器数量大约有两百台。对于这样一个规模的系统而言，排查故障的难度之大是显而易见的。

鉴于此，我结合 ELK 的特性，设计了一套极为简单的全量日志分布式链路跟踪方案。通过这一方案，将日志有效地串联起来，从而极大地降低了系统排查的难度。

目前，市面上开源的分布式链路跟踪普遍较为抽象。当业务复杂程度达到一定水平时，为核心系统定制一个符合自身业务需求的链路跟踪就显得非常有必要了。

事实上，实现一个分布式链路跟踪并非难事，真正具有挑战性的是在埋点、数据传输、存储以及分析等方面。如果你的团队具备这些方面的能力，那么也能够迅速制作出一个链路跟踪系统。

接下来，让我们一同探讨如何实现一个简单的定制化分布式链路跟踪。

监控行业发展现状

在学习制作简单的分布式链路跟踪之前，为了更好地理解这个链路跟踪的设计特点，我们先来简单了解一下监控行业的现状。近期，监控行业经历了一次重大革新。现代的链路跟踪标准不再局限于对请求的链路跟踪，目前已经开始进行融合。新的标准与我们定制化的分布式链路跟踪的设计思路极为相似，即将 Trace（追踪）、Metrics（指标）以及日志合并成一套系统进行建设。

在此之前，常见监控系统主要有三种类型：Metrics、Tracing 和 Logging。

常见的开源 Metrics 有 Zabbix、Nagios、Prometheus、InfluxDb、OpenFalcon，主要做各种量化指标汇总统计，比如监控系统的容量剩余、每秒请求量、平均响应速度、某个时段请求量多少。常见的开源链路跟踪有 Jaeger、Zipkin、Pinpoint、Skywalking，主要是通过分析每次请求链路监控分析的系统，我么可以通过 TraceID 查找一次请求的依赖及调用链路，分析故障点和传导过程的耗时。

常见的开源 Logging 方案有 ELK、Loki、Loggly 等，其主要功能是对文本日志进行收集、归类和整理，能够对错误日志进行汇总、发出警告，并分析系统的错误异常等情况。这三种监控系统可以说是大服务集群监控的重要支柱，它们各自具有优点，但一直以来都是分别建设的。这使得我们的系统监控存在一定的割裂感以及功能重复的问题，并且每一个标准都需要独立建设一个系统，然后在不同的界面针对同一个故障进行分析，在排查问题时十分不便。

随着行业的发展，三位一体的标准应运而生，即 OpenTelemetry 标准（它集成了 OpenCensus、OpenTracing 标准）。这个标准将 Metrics（指标）、Tracing（追踪）和 Logging（日志）集成于一体，如此一来，我们在监控系统时就可以从三个维度综合观测系统的运转情况。常见的 OpenTelemetry 开源项目中的 Prometheus、Jaeger 正在遵循这个标准逐步改进。OpenTelemetry 实现的结构如下图所示：

事实上，分布式链路跟踪系统及监控主要提供了一系列支撑服务，包括监控日志标准埋点 SDK（可以是 AOP 方式或侵入式）、日志收集、分布式日志传输、分布式日志存储、分布式检索计算、分布式实时分析、个性化定制指标盘以及系统警告。

我建议使用 ELK 所提供的功能来实现分布式链路跟踪系统，因为它已经完整地提供了如下功能：日志收集（由 Filebeat 实现）、日志传输（通过 Kafka 与 Logstash）、日志存储（利用 Elasticsearch）、检索计算（由 Elasticsearch 和 Kibana 共同完成）以及实时分析（通过 Kibana）、个性定制表格查询（借助 Kibana）。这样一来，我们只需要制定日志格式并开发埋点 SDK，就能够实现一个具备分布式链路跟踪、Metrics 和日志分析功能的系统。

事实上，Log（日志）、Metrics（指标）、trace（追踪）这三种监控体系最大的区别在于日志格式标准，而底层实现其实是非常相似的。既然 ELK 已经提供了我们所需的分布式相关服务，下面我就简单讲讲日志格式和 SDK 埋点，通过这两个方面，我们就可以大致了解分布式链路跟踪的全貌。

TraceID 单次请求标识

可以说，要想构建一个简单的 Trace 系统，我们首先要做的就是生成并传递 TraceID。

分布式链路跟踪的原理其实并不复杂。在请求发起方发送请求时或者服务被请求时，会生成一个 UUID。在被请求期间，业务产生的任何日志（包括 Warning、Info、Debug、Error 等类型）、任何依赖资源请求（如 MySQL、Kafka、Redis 等）以及任何内部接口调用（如 Restful、Http、RPC 等）都会带上这个 UUID。

这样一来，当我们把所有拥有同样 UUID 的日志收集起来时，就可以根据时间（存在一定误差）、RPCID（后续会介绍 RPCID）或者 SpanID，将这些日志按照依赖请求顺序串联起来。只要日志足够详细，我们就能监控到系统的大部分工作状态。

例如，用户请求一个服务会调用多少个接口，每个数据查询的 SQL 以及具体耗时是多少，调用的内网请求参数是什么，调用的内网请求返回的内容是什么，内网被请求的接口又做了哪些操作，产生了哪些异常信息等等。

同时，我们可以通过对这些日志进行归类分析，分析项目之间的调用关系、项目整体健康程度，对链路进行深挖还能自动识别出故障点等。这有助于我们主动、快速地查找问题。

“RPCID” VS “SpanID 链路标识”

那么如何将汇总起来的日志串联起来呢？有两种方式：span（链式记录依赖）和 RPCID（层级计数器）。我们在记录日志带上 UUID 的同时，也带上 RPCID 这个信息，通过它帮我们把日志关联关系串联起来，那么这两种方式有什么区别呢？我们先看看 span 实现，具体如下图：

结合上图，我们来分析一下 span 的链式依赖记录方式。就代码而言，许多编写的功能会被封装成功能模块（如 Service、Model），我们通过组合不同的模块来实现业务功能，并且记录这两个模块、两个服务之间或者资源的调用依赖关系。span 的设计会通过记录自己上游依赖服务的 SpanID 来实现上下游关系的关联（将其放在 Parent ID 中），通过整理 span 之间的依赖关系，就能够组合成一个调用链路树。

那么 RPCID 方式又是怎样的呢？RPCID 也被称为层级计数器，我在微博和好未来时都曾使用过。为了方便理解，我们来看下面这张图。

你瞧，RPCID 的层级计数器实现起来非常简单。第一个接口生成 RPCID 为 1.1，其中 RPCID 的前缀是 1，计数器是 1（日志记录为 1.1）。当所在接口去请求其他接口或者数据服务（比如 MySQL、Redis、API、Kafka）时，计数器会加 1，并在请求当中带上 1.2 这个数值（因为当前的前缀加上 “.” 再加上计数器值等于 1.2）。等到返回结果后，继续请求下一个资源时继续加 1，在此期间产生的任何日志都会记录当前的前缀加上 “.” 再加上计数器值。

每一层收到了前缀后，都在后面加了一个累加的计数器，实际效果如下图所示：

而被请求的接口在收到请求时，如果请求传递了 TraceID，那么被请求的服务会继续使用传递过来的 TraceID；如果请求没有 TraceID，则自己生成一个。同样地，如果传递了 RPCID，那么被请求的服务会将传递来的 RPCID 当作前缀，计数器从 1 开始计数。

相对于 span，通过这个层级计数器做出来的 RPCID 有两个优点。

第一个优点是我们可以记录请求方日志。如果被请求方没有记录日志，那么还可以通过请求方日志观测分析被调用方性能（比如 MySQL、Redis）。

第二个优点是哪怕日志收集得不全，丢失了一些，我们还可以通过前缀有几个分隔符，判断出日志所在层级进行渲染。举个例子，假设我们不知道上图的 1.5.1 是谁调用的，但是根据它的 UUID 和层级 1.5.1 这些信息，在渲染的时候，我们仍旧可以渲染它大概的链路位置。

除此之外，我们可以利用 AOP 顺便将各个模块做一个 Metrics 性能统计分析，分析各个模块的耗时、调用次数并做周期统计。同时，通过这个维度采样统计数据，能够帮助我们分析这个模块的性能和错误率。由于 Metrics 这种方式产生的日志量很小，有些统计是每 10 秒才会产生一条 Metrics 统计日志，统计的数值很方便对比，很有参考价值。但是你要注意，对于一个模块内有多个分支逻辑时，Metrics 很多时候取的是平均数，偶发的超时在平均数上看不出来，所以我们需要另外记录一下最大最小的延迟，才可以更好地展现。同时，这种统计只是让我们知道这个模块是否有性能问题，但是无法帮助我们分析具体的原因。

• 以将其放在 Header 中传递。
• RPC 协议可放在 meta 中进行传递。
  • 对于队列，可以放在消息体的 Header 中，或者直接在消息体中传递。
  • 在其他特殊情况下，可以通过网址请求参数进行传递。

那么，应用内多线程和多协程之间如何传递 TraceID 呢？一般来说，我们会通过复制一份 Context 传递进入线程或协程。并且如果它们之前是并行关系，我们复制之后需要对下发之前的 RPCID 计数器加 1，并把前缀和计数器合并成新的前缀，以此区分并行的链路。

除此之外，我们还做了一些特殊设计。当我们的请求中带有一个特殊的密语，并且设置类似 X-DEBUG Header 等于 1 时，我们可以开启在线 debug 模式。在这种模式下，被调用接口及所有依赖的服务都会输出 debug 级别的日志，这样我们临时排查线上问题会更加方便。

日志类型定义

可以说，只要让日志输出当前的 TraceId 和 RPCID（SpanID），并在请求所有依赖资源时把计数传递给它们，就完成了大部分的分布式链路跟踪。下面是我定制的一些日志类型和日志格式，供你参考：

## 日志类型 
* request.info 当前被请求接口的相关信息，如被请求接口，耗时，参数，返回值，客户端信息 
* mysql.connect mysql连接时长 
* mysql.connect.error mysql链接错误信息 
* mysql.request mysql执行查询命令时长及相关信息 
* mysql.request.error mysql操作时报错的相关信息 
* redis.connect redis 链接时长 
* redis.connect.error redis链接错误信息 
* redis.request redis执行命令 
* redis.request.error redis操作时错误 
* memcache.connect 
* memcache.connect.error 
* memcache.request.error 
* http.get 另外可以支持restful操作get put delete 
* http.post 
* http.*.error 
## Metric日志类型 
* metric.counter 
...略 
## 分级日志类型 
* log.debug: debug log 
* log.trace: trace log 
* log.notice: notice log 
* log.info: info log 
* log.error: application error log 
* log.alarm: alarm log 
* log.exception: exception log

日志格式样例

日志建议使用 JSON 格式，所有字段除了标注为 string 的都建议保存为字符串类型，每个字段必须是固定数据类型，选填内容如果没有内容就直接不输出。这样设计其实是为了适配 Elasticsearch+Kibana，Kibana 提供了日志的聚合、检索、条件检索和数值聚合，但是对字段格式很敏感，不是数值类型就无法聚合对比。下面我给你举一个例子用于链路跟踪和监控，你主要关注它的类型和字段用途。

{ 
"name": "string:全量字段介绍,必填，用于区分日志类型，上面的日志列表内容写这里", 
"trace_id": "string:traceid，必填", 
"rpc_id": "string:RPCID，服务端链路必填，客户端非必填", 
"department":"部门缩写如client_frontend 必填", 
"version": "string:当前服务版本 cpp-client-1.1 php-baseserver-1.4 java-rti-1.9，建议都填", 
"timestamp": "int:日志记录时间，单位秒，必填", 
"duration": "float:消耗时间，浮点数 单位秒，能填就填", 
"module": "string:模块路径，建议格式应用名称_模块名称_函数名称_动作，必填", 
"source": "string:请求来源 如果是网页可以记录ref page，选填", 
"uid": "string:当前用户uid，如果没有则填写为 0长度字符串，可选填，能够帮助分析用户一段时间行为", 
"pid": "string:进程pid，如果没有填写为 0长度字符串，如果有线程可以为pid-tid格式，可选填", 
"server_ip": "string 当前服务器ip，必填", 
"client_ip": "string 客户端ip，选填", 
"user_agent": "string curl/7.29.0 选填", 
"host": "string 链接目标的ip及端口号，用于区分环境12.123.23.1:3306，选填", 
"instance_name": "string 数据库连接配置的标识，比如rti的数据库连接，选填", 
"db": "string 数据库名称如：peiyou_stastic，选填", 
"code": "string:各种驱动或错误或服务的错误码，选填，报错误必填", 
"msg": "string 错误信息或其他提示信息，选填，报错误必填", 
"backtrace": "string 错误的backtrace信息，选填，报错误必填", 
"action": "string 可以是url、sql、redis命令、所有让远程执行的命令，必填", 
"param": "string 通用参数模板，用于和script配合，记录所有请求参数，必填", 
"file": "string userinfo.php，选填", 
"line": "string 232，选填", 
"response": "string:请求返回的结果，可以是本接口或其他资源返回的数据，如果数据太长会影响性能，选填", 
"response_length": "int:相应内容结果的长度，选填", 
"dns_duration": "float dns解析时间，一般http mysql请求域名的时候会出现此选项，选填", 
"extra": "json 放什么都可以,用户所有附加数据都扔这里" 
} 
## 样例 
被请求日志 
{ 
"x_name": "request.info", 
"x_trace_id": "123jiojfdsao", 
"x_rpc_id": "0.1", 
"x_version": "php-baseserver-4.0", 
"x_department":"tal_client_frontend", 
"x_timestamp": 1506480162, 
"x_duration": 0.021, 
"x_uid": "9527", 
"x_pid": "123", 
"x_module": "js_game1_start", 
"x_user_agent": "string curl/7.29.0", 
"x_action": "http://testapi.speiyou.com/v3/user/getinfo?id=9527", 
"x_server_ip": "192.168.1.1:80", 
"x_client_ip": "192.168.1.123", 
"x_param": "json string", 
"x_source": "www.baidu.com", 
"x_code": "200", 
"x_response": "json:api result", 
"x_response_len": 12324 
} 
### mysql 链接性能日志 
{ 
"x_name": "mysql.connect", 
"x_trace_id": "123jiojfdsao", 
"x_rpc_id": "0.2", 
"x_version": "php-baseserver-4", 
"x_department":"tal_client_frontend", 
"x_timestamp": 1506480162, 
"x_duration": 0.024, 
"x_uid": "9527", 
"x_pid": "123", 
"x_module": "js_mysql_connect", 
"x_instance_name": "default", 
"x_host": "12.123.23.1:3306", 
"x_db": "tal_game_round", 
"x_msg": "ok", 
"x_code": "1", 
"x_response": "json:****" 
} 
### Mysql 请求日志 
{ 
"x_name": "mysql.request", 
"x_trace_id": "123jiojfdsao", 
"x_rpc_id": "0.2", 
"x_version": "php-4", 
"x_department":"tal_client_frontend", 
"x_timestamp": 1506480162, 
"x_duration": 0.024, 
"x_uid": "9527", 
"x_pid": "123", 
"x_module": "js_game1_round_sigup", 
"x_instance_name": "default", 
"x_host": "12.123.23.1:3306", 
"x_db": "tal_game_round", 
"x_action": "select * from xxx where xxxx", 
"x_param": "json string", 
"x_code": "1", 
"x_msg": "ok", 
"x_response": "json:****" 
} 
### http 请求日志 
{ 
"x_name": "http.post", 
"x_trace_id": "123jiojfdsao", 
"x_department":"tal_client_frontend", 
"x_rpc_id": "0.3", 
"x_version": "php-4", 
"x_timestamp": 1506480162, 
"x_duration": 0.214, 
"x_uid": "9527", 
"x_pid": "123", 
"x_module": "js_game1_round_win_report", 
"x_action": "http://testapi.speiyou.com/v3/game/report", 
"x_param": "json:", 
"x_server_ip": "192.168.1.1", 
"x_msg": "ok", 
"x_code": "200", 
"x_response_len": 12324, 
"x_response": "json:responsexxxx", 
"x_dns_duration": 0.001 
} 
### level log info日志 
{ 
"x_name": "log.info", 
"x_trace_id": "123jiojfdsao", 
"x_department":"tal_client_frontend", 
"x_rpc_id": "0.3", 
"x_version": "php-4", 
"x_timestamp": 1506480162, 
"x_duration": 0.214, 
"x_uid": "9527", 
"x_pid": "123", 
"x_module": "game1_round_win_round_end", 
"x_file": "userinfo.php", 
"x_line": "232", 
"x_msg": "ok", 
"x_code": "201", 
"extra": "json game_id lesson_num  xxxxx" 
} 
### exception 异常日志 
{ 
"x_name": "log.exception", 
"x_trace_id": "123jiojfdsao", 
"x_department":"tal_client_frontend", 
"x_rpc_id": "0.3", 
"x_version": "php-4", 
"x_timestamp": 1506480162, 
"x_duration": 0.214, 
"x_uid": "9527", 
"x_pid": "123", 
"x_module": "game1_round_win", 
"x_file": "userinfo.php", 
"x_line": "232", 
"x_msg": "exception:xxxxx call stack", 
"x_code": "hy20001", 
"x_backtrace": "xxxxx.php(123) gotError:..." 
} 
### 业务自发告警日志 
{ 
"x_name": "log.alarm", 
"x_trace_id": "123jiojfdsao", 
"x_department":"tal_client_frontend", 
"x_rpc_id": "0.3", 
"x_version": "php-4", 
"x_timestamp": 1506480162, 
"x_duration": 0.214, 
"x_uid": "9527", 
"x_pid": "123", 
"x_module": "game1_round_win_round_report", 
"x_file": "game_win_notify.php", 
"x_line": "123", 
"x_msg": "game report request fail! retryed three time..", 
"x_code": "201", 
"x_extra": "json game_id lesson_num  xxxxx" 
} 
### matrics 计数器 
{ 
"x_name": "metrix.count", 
"x_trace_id": "123jiojfdsao", 
"x_department":"tal_client_frontend", 
"x_rpc_id": "0.3", 
"x_version": "php-4", 
"x_timestamp": 1506480162, 
"x_uid": "9527", 
"x_pid": "123", 
"x_module": "game1_round_win_click", 
"x_extra": "json curl invoke count" 
}

这个日志不仅能应用于服务端，在客户端同样适用。每当客户端被点击或者触发某个操作时，都可以自行生成一个新的 TraceID，在向服务端发起请求时将其带上。通过这些日志，我们能够分析不同地域访问服务的性能，也可以将其作为用户行为日志使用，只需添加相应的日志类型就行。

上面提及的日志示例已经把我们所依赖的资源情况描述得比较清楚了。另外，还有一个补充技巧：性能记录日志可以把被请求的接口也记录为一个日志，记录它的耗时等信息，方便之后和请求方的请求日志进行对照，这样就能分析出两者之间是否存在网络延迟等问题。

除此之外，这个设计有一个核心要点：研发人员不一定要完全遵循上述的字段规则来生成日志。业务方面只要确保在项目范围内输出的日志包含所有必填项目（TraceID、RPCID/SpanID、TimeStamp），同时保证数值型字段的功能和类型稳定，就可以实现 trace。我们完全能够在汇总日志之后，再对不同的日志字段进行自行解释，定制出符合不同业务需求的统计分析，这正是 ELK 最强大的地方。

为什么大部分设计都是记录依赖资源的日志呢？这是因为在没有 IO 操作的情况下，程序大部分是可控的（侧重计算的服务除外）。只有 IO 类操作容易出现不稳定因素，并且日志记录过多也会对系统性能产生影响。通过记录对数据源的操作，有助于我们排查业务逻辑方面的错误。

我们刚才提到日志过多会影响接口性能，那么如何提高日志的写吞吐能力呢？这里为你归纳了几个注意事项和技巧：

1. 增加写线程的数量，让一个线程负责写一个日志，也可以把每个日志文件存放在单独的磁盘中。不过要注意控制系统的 IOPS（每秒的输入 / 输出操作次数）不超过 100。
2. 当写入日志的长度超过 1kb 时，不要使用多个线程高并发地写同一个文件。原因可以参考 “append is not Atomic”，简单来讲，文件的 append 操作对于写入长度超过缓冲区长度的操作不是原子性的。多线程并发地将长内容写入同一个文件，会导致日志顺序混乱。
3. 日志可以先在内存中暂存，汇总到一定的数据量或者缓存超过 2 秒之后再写入磁盘，这样可以减少过小日志对磁盘系统调用的次数。不过这样做的代价是服务被强制关闭时会丢失日志。
4. 日志缓存要提前使用固定长度进行 malloc 缓存，不要频繁地分配和回收，否则会导致系统整体运行缓慢。
5. 服务被 kill 时，要记得拦截信号，快速将内存中的日志 fsync（同步）到磁盘，以此减少日志丢失的可能性。

“侵入式埋点 SDK”VS“AOP 方式埋点”

最后，我们来说说 SDK。事实上，使用 “ELK + 自定义的标准” 基本上已经能够实现大多数的分布式链路跟踪系统。使用 Kibana 可以很快速地对各种日志进行聚合分析统计。虽然行业中出现过很多链路跟踪系统服务公司，也做了很多 APM 等类似产品，但是真正能推广开来的服务实际上占少数。究其原因，我认为有以下几点：

首先，分布式链路跟踪的日志吞吐量很大，需要耗费大量的资源，成本高昂。其次，通用的分布式链路跟踪服务很难做到贴近业务的个性化，不能定制的第三方服务不如使用开源方案。再者，分布式链路跟踪的埋点库对代码的侵入性大，需要研发人员手动植入到业务代码里，操作很麻烦，而且不够灵活。

另外，这种做法对语言也有相关限制，因为目前只有 Java 通过动态启动注入 agent，才实现了静态语言的 AOP 注入。我之前推广时，也是统一了内网项目的开源框架，才实现了统一的链路跟踪。

那么，如果底层代码不能更新，如何简单暴力地实现链路跟踪呢？这时候我们可以改造分级日志，让它每次在落地的时候都把 TraceId 和 RPCID（或 SpanID）带上，这样就会有很好的效果。如果数据底层做了良好的封装，我们可以在发起请求部分中写一些符合标准性能的日志，在框架的统一异常处理中也注入我们的标准跟踪，即可实现关键点的监控。

当然，如果条件允许，我们最好提供一个标准的 SDK，让业务研发伙伴按需调用，这能帮助我们统一日志结构。毕竟手写很容易格式错乱，需要人工梳理，不过即使混乱，也仍旧有规律可言。这是 ELK 架构的强大之处，它的全文检索功能其实不在乎你的输入格式，但是数据统计类却需要我们确保各个字段用途固定。

最后再讲点其他日志的注意事项。可能你已经注意到了，这个设计的日志是全量的。很多链路跟踪其实都是采用采样方式，比如 Jaeger 在应用本地会部署一个 Agent，对数据暂存汇总，统计出每个接口的平均响应时间，对具有同样特征的请求进行归类汇总，这样可以大大降低服务端压力。但这么做也有缺点，当我们有一些小概率的业务逻辑错误时，在采样中会被遗漏。

所以很多核心系统会记录全量日志，周边业务记录采样日志。由于我们的日志结构很简单，如有需要可以自行实现一个类似 Agent 的功能，降低我们的存储计算压力。甚至我们可以在服务端本地保存原始日志 7 天，当我们查找某个 Trace 日志的时候，直接请求所有服务器在本地查找。

总结

系统监控一直是服务端重点关注的功能。

我们常常会根据链路跟踪和过程日志，去分析排查线上问题。也就是说，监控越是贴近业务、越定制化，我们对线上业务运转情况的了解就越直观。

不过，实现一个更符合业务的监控系统并不容易。基础运维监控只会监控线上请求流量、响应速度、系统报错、系统资源等基础监控指标。当我们要监控业务时，还需要人工在业务系统中嵌入大量代码。而且，因为这些服务属于开源，还要求我们必须对监控有较深的了解，投入大量精力才可以。

好在技术逐渐成熟，通用的简单日志传输索引统计服务开始流行，其中最强的组合就是 ELK。通过这类分布式日志技术，能让我们轻松实现个性化监控需求。日志格式很杂乱也没关系，只要将 TraceID 和 RPCID（或 SpanID）在请求依赖资源时传递下去，并将沿途的日志都记录对应的字段即可。

也正因如此，ELK 流行起来，很多公司的核心业务，都会依托 ELK 自定义一套自己的监控系统。不过这么做，只能让我们建立起一个粗旷的跟踪系统，后续分析的难度和投入成本依然很大，因为 ELK 需要投入大量硬件资源来帮我们处理海量数据。