如何根据日志来了解一个请求经历了什么?

上一篇我们介绍了服务的注册发现,本篇文章我们再来聊聊另一个问题——全链路日志。

为了便于理解,我们依然从业务场景入手。

一、业务场景

当时公司的微服务刚刚迁移到Springcloud,服务注册发现基于Spring Cloud Zookeeper实现,不过组件方面只使用了Spring Cloud的服务间调用(Feign)。

迁移到微服务之后,就得考虑日志跟踪的事情了。

之前我们只是简单把日志打印到本地文件上,然后使用ELK进行日志收集、分析、,因此日志记录比较随意且没有形成一个统一的规范。

与技术人员商量后,我们决定把日志进一步规范化,于是提出了如下3点需求:

1、记录什么时候调用了缓存/MQ/ES等中间件,在哪个类的哪个方法耗时多久?

2、记录什么时候调用了数据库,执行了什么SQL,耗时多久?

3、记录什么时候调用了另一个服务,服务名是什么?方法名是什么?耗时多久?

一般来说,一个请求会跨多个服务节点,针对这种情况我们又梳理了2条重要需求。

1、把同一个请求在全部服务的以上所有记录进行串联,最终实现一个树状的记录。

2、设计一个机遇这些基础数据的查询统计功能。

通过以上需求梳理并将日志规范后,我们就可以在一个页面上看到每个请求的树状结构日志了,如下图所示,仅供参考:
如何根据日志来了解一个请求经历了什么?

通过这样的操作,如果后期线上环境出现问题需要进一步调查,我们就有了更多的依据。

需求提完后,我们就需要选择一款真正适合的开源技术进行方案实现,这就涉及技术选型过程。

二、技术选型

在技术选型时,可以看看下方的框架对比表,如图所示:
如何根据日志来了解一个请求经历了什么?
在上表中我们发现,可供选择的系统太多了,我们该如何选择呢?通过与其他技术同事的讨论,最终商量出了如下标准。

1、日志数据结构支持OpenTracing

平时日志行都是单独记录的,我们只能通过线程id把它们关联起来,因此我们需要一个数据结构把每个请求在全部服务的相关日志关联起来。

而且市面上已经有1个比较通用的全链路数据格式-OpenTracing,它的标准和API是由一个开源的组织(Cloud Native Conmmputing Foundation 云原生计算基金会孵化)进行维护,这个开源组织也包含了一些全链路日志系统的维护者。

OpenTracing 通过提供一个与平台/厂商无关的 API,使得开发人员能够更方便地添加(或更换)追踪系统。这样就算我们之前引入的全链路日志不好用,以后想再换掉也是超级方便。

接下来我们解释下 OpenTracing 标准,它主要包含两个概念:一个是 Trace,一个是 Span。

我们先来看看下面的例子,如下图所示。
如何根据日志来了解一个请求经历了什么?
在上图中,我们看到一个客户端调用 Order API 的请求时经历的整个流程(1 到 10),即 1 个 Trace,之后它又调用了 Product Service 的整个过程(2 到 5),这就是 1 个 Span,每个 Span 代表 Trace 中被命名且被计时的连续性执行片段。

通过上图我们还发现,Span 中又包含了一个子 Span,比如调用 Product Service 的过程中,Product Service 会访问一次数据库(3 到 4),这也是一个 Span。因此,我们可以得出一个 Span 可以包含多个子 Span,而 Span 与 Span 之间的关系就叫 Reference。

在技术选型时,大家都认可:必须保证系统的可替代性,尽量别在一项开源技术上绑死。因为以前我们吃过一次大亏,强依赖了一个框架,结果那个框架不维护了,后面维护相关代码的人就非常痛苦。但是如果全部迁移掉,代价又太大且工作量也很大,付出与回报产出比不足以说服领导进行决策。要是不迁移,我们就只能一直用着上个年代的技术,所以这次选型我们坚决使用基于 OpenTracing 的日志系统。

2、支持Elasticsearch作为存储系统

诚然,因为流量大的原因,导致我们记录的日志数据量也很大,这就要求存储这些日志的系统必须支持海量数据且保证查询高效。

最终,因为公司运维同事对 Elasticsearch 比较熟悉,所以我们提出可以使用 Elasticsearch 对日志进行存储。

3、保证日志的收集对性能无影响

当服务正在记录日志,我们需要确保日志的记录与收集对服务器的性能不会产生影响。

比如之前我们调研过 Pinpoint,当服务正在记录日志,Pinpoint 的并发数达到了一定数量且整体吞吐量少了一半,对服务器的性能影响很大,这肯定不行。

4、查询统计功能的丰富程度

一般来说,查询统计的功能越丰富越好,但必须首先满足一个基础功能:支持每个请求树状结构的全链路日志(如下图所示),比如 SkyWalking 的功能就非常适用。
如何根据日志来了解一个请求经历了什么?

如何根据日志来了解一个请求经历了什么?

查询系统除了满足基本功能以外,我们也想实现监控报警、指标统计等功能,以此帮助我们减轻一堆二次开发的工作量。

5.如何以最小的业务代码侵入性引入系统

我们希望日志数据的收集过程对写业务代码的人保持透明,因此,最理想的解决方案是使用 Java 的探针,通过字节码加强的方式进行埋点。不过,这种方式对系统性能也会产生一定影响。

而且在实际业务中,公司都会把对数据库、Redis、MQ 访问的代码进行封装,我们无法通过字节码加强的方式实现埋点,只能尝试在封装的代码中实现埋点了,这样对开发业务代码的人来说同样透明。

6.客户案例

技术选型时,我们往往还需要了解哪些知名公司使用了这个技术,因为大公司的业务场景相对复杂些,提前踩的坑较多,一个技术如果被很多公司都使用过了,那我们使用起来也就会平稳很多。

以上就是技术选型时需考虑的几个问题,大家有更好的想法可以留言我再补充上来。

7.最终选择

根据以上问题的剖析及性能测试结果的分析,我们发现 SkyWalking 比较符合我们的需求。

不过,做性能测试时,我们发现 500 线程压力以下的服务是否使用 SkyWalking 对服务的吞吐量影响不大,差别一般不超过 10%。

在 SkyWalking 官方测试报告中也提道:假如有 500 个并发用户,每个用户的每次请求间隔是 10ms,TPS 基本没什么变化,如下图所示。

如何根据日志来了解一个请求经历了什么?

技术选型时我们经常提到,不仅仅需要关注需求本身,还需要考虑组织或个人主观上的因素。

三、注意事项

在安心使用 SkyWalking 之前,我们还需要注意如下 5 大注意事项。

1、 SkyWalking 的数据收集机制

SkyWalking 数据收集机制是这样的:服务中有一个本地缓存,我们把收集的所有日志数据先存放在这个缓存中,然后后台线程通过异步的方式将缓存中的日志发送给 SkyWalking 服务端。通过这种机制,在日志埋点的地方,我们无须等待服务端接收受数据,也就不影响系统性能。

2、如果 SkyWalking 服务端宕机了,会出现什么情况?

如果服务端宕机了,理论上日志缓存中的数据会出现没人消费的情况,这样会不会导致数据越积越多,最终撑爆内存呢?

在 SkyWalking 中,我们会设置缓存的 size,如果这部分数据超出了缓存 size,Trace 不会保存,我们也就知道内存会不会撑爆了。

3、流量较大时,如何控制日志的数据量?

流量大时,我们不可能收集每个请求的日志,这样数据量太大了。那 SkyWalking 如何控制采样比例呢?

SkyWalking 会在每个服务器上配置采样比例,比如设置为 100,代表 1% 的请求数据会被收集,如下代码所示。

agent-analyzer:
  default:
    ...
    sampleRate: ${SW_TracE_SAMPLE_RATE:1000} # The sample rate precision is 1/10000. 10000 means 100% sample in default.
    forceSampleErrorSegment: ${SW_FORCE_SAMPLE_ERROR_SEGMENT:true} # When sampling mechanism activated, this config would make the error status segment sampled, ignoring the sampling rate.

这样,我们就可以通过 sampleRate 控制采样比率了,一般而言,流量越大,采样比例越小。

不过,这里有 2 点需要特别注意。

  • 一旦启用 forceSampleErrorSegment ,出现错误时所有的数据全部会收集,此时 sampleRate 对出错的请求不再适用。
  • 所有相关联服务的 sampleRate 最好保持一致,如果 A 调用 B,然后 A、B 的采样率不一样,就会出现一个 Trace 串不起来的情况。

4、日志的保存时间

一般来说,日志不需要永久保存,通常我们是保存 3 个月的数据,关于这点大家结合公司的实际情况进行配置即可,如果你是土豪那请随意。

按照以前的设计方案,我们需要自己设计一个工具将数据进行定时清理,不过此时我们可以直接使用 SkyWalking 进行配置,如下代码所示:

    # Set a timeout on metrics data. After the timeout has expired, the metrics data will automatically be deleted.
    recordDataTTL: ${SW_CORE_RECORD_DATA_TTL:3} # Unit is day
    metricsDataTTL: ${SW_CORE_METRICS_DATA_TTL:7} # Unit is day

5、集群配置:如何确保高可用?

我们先来看看 SkyWalking 的架构:
如何根据日志来了解一个请求经历了什么?

在以上架构中,我们需要关注 SkyWalking 的收集服务(Receiver)和聚合服务(Aggregator),它们支持集群模式。同时呢,在集群服务里,多个服务节点又需要一些协调服务来协调服务间的关系,它们支持 Kubernetes-ZooKeeper、Consul、Etcd、Nacos(开源的协调服务基本支持)。

前面的课时我们提及 ZooKeeper 太多次了,此时你应该猜得到我们最终的选型了吧。

五、总结

在我们的方案中使用了 SkyWalking 后,在问题排查这个方面帮助非常大,但是 SkyWalking 也存在不足,比如之前的版本存在很多兼容性问题,不过现在好多了。

六、联系我

公众号:服务端技术精选;

上一篇:SkyWalking 后端服务存储配置


下一篇:​飘飞的绿叶之 spring-cloud 链路追踪