25 | 分布式Trace:横跨几十个分布式组件的慢请求要如何排查?


经过前面几节的梳理,我们的架构现如下:

经过服务的拆分 服务的扩展性增强了,横向扩展也更平滑了,应对峰值的流量更得心应手了。

这个时候发现个问题,在下单高峰时间会有少量慢请求,而一个下单流程会调用很多服务,很难决断究竟哪个资源或者服务产生了问题,于是 开始排查这个问题。

一体化架构中的慢请求排查如何做

我们先来看下一体化架构中如何排查,最简单的就是打印下单操作每一个步骤的耗时,找到延迟最高的一部,然后开始优化。代码如下:

long start = System.currentTimeMillis();
processA();
Logs.info("process A cost " + (System.currentTimeMillis() - start));//打印A步骤的耗时
start = System.currentTimeMillis();
processB();
Logs.info("process B cost " + (System.currentTimeMillis() - start));//打印B步骤的耗时
start = System.currentTimeMillis();
processC();
Logs.info("process C cost " + (System.currentTimeMillis() - start));//打印C步骤的耗时

但是 这样打出来的日志比较乱,没法轻松定位一次完整的请求,这个时候 我们是不是给每次请求打个标记,比如RequestId ?

有了这个字段,就可以清晰了解一个调用链路上耗时分布。

如何来做分布式 Trace

你可能会问:题目既然是“分布式 Trace:横跨几十个分布式组件的慢请求要如何排查?”,那么我为什么要花费大量的篇幅来说明在一体化架构中如何排查问题呢?这是因为在分布式环境下,你基本上也是依据上面我提到的这几点来构建分布式追踪的中间件的。

在一体化架构中,单次请求的所有的耗时日志都被记录在一台服务器上,而在微服务的场景下,单次请求可能跨越多个 RPC 服务,这就造成了单次的请求的日志会分布在多个服务器上。

我来给你讲讲图中的内容:

  1. 用户到 A 服务之后会初始化一个 traceId 为 100,spanId 为 1;
  2. A 服务调用 B 服务时,traceId 不变,而 spanId 用 1.1 标识代表上一级的 spanId 是 1,这一级的调用次序是 1;
  3. A 调用 C 服务时,traceId 依然不变,spanId 则变为了 1.2,代表上一级的 spanId 还是 1,而调用次序则变成了 2,以此类推。

通过这种方式,我们可以在日志中清晰地看出服务的调用关系是如何的,方便在后续计算中调整日志顺序,打印出完整的调用链路。

那么 spanId 是何时生成的,又是如何传递的呢?这部分内容可以算作一个延伸点,能够帮你了解分布式 Trace 中间件的实现原理。

而在这里,你大概率会遇到的问题还是性能的问题,也就是因为引入了分布式追踪中间件,导致对于磁盘 I/O 和网络 I/O 的影响,而我给你的“避坑”指南就是:如果你是自研的分布式 Trace 中间件,那么一定要提供一个开关,方便在线上随时将日志打印关闭;如果使用开源的组件,可以开始设置一个较低的日志采样率,观察系统性能情况再调整到一个合适的数值。

举报
评论 0