基于ByteBuddy以Java Agent方式实现的轻量级日志跟踪工具autotrace4j

1,279 阅读5分钟

如果这个项目对你有帮助,请顺手给个star,autotrace4j: github.com/artlibs/aut…

一、需求描述

1、现状

  • 在应用系统当中存在多个Java服务(业务A服务、业务B服务,MQ消费服务、短信/推送/ABTest配置/等基础服务),各个服务独立项目并可能由不同团队进行迭代开发,各自在日志中台(例如Kibana、Aliyun SLS等)收集了日志。

2、目标

  • 期望使用一个或多个ID标识查询出某次请求涉及的所有日志,以方便开发、测试定位问题、排查原因和解决问题,提升开发效率和生产问题定位解决效率。
  • 解决方案应当具备如下要求:
    • 轻量级:不增加现有应用的性能开销
    • 接入简便而快速:步骤简便,现有应用接入不需要改动或只需要极少改动
    • 接入过程中的沟通/落地成本最低:支持团队自顶向下快速所有项目接入(例如运维在启动脚本中统一接入,通过java agent方式)

二、可选方案

  • Spring Cloud Sleuth
    • 需要以maven包的方式接入,团队推广落地成本高
    • 额外收集了其他信息且上报服务端,增加了应用开销
  • Apache Skywalking
    • 额外收集了其他信息且上报服务端,增加了应用开销
  • 各类应用服务监控Arms
    • 额外收集了其他信息且上报服务端,增加了应用开销

三、自研方案

参考了Apache Skywalking,使用Java Agent方式实现以实现快速方便接入,只增强关键代码节点且在增强逻辑中做极少的事情(仅增加ThreadLocal设置一个字符串ID),以尽可能保证不增加额外开销。

名词解释

词汇解释
全链路一次跨越不同服务(或相同服务的不同)组件、线程的逻辑执行流过程:例如从一个客户端发起请求到WEB,WEB服务的HTTP IO线程又起了异步线程,或者是发送了MQ消息,消费者消费消息等整个请求执行过程
上下文(Context)一次执行逻辑流区间,例如一次HTTP请求的同步处理部分,一次异步线程任务,一次MQ消费等等
Trace ID贯穿【全链路】的一个相同的字符串ID,在一次逻辑链路处理流当中它保持一致,用以标识本次处理流(串联起所有上下文 —— 在一次全链路过程中所有上下文的Trace ID都相同)
Span ID区间ID,可理解为一个上下文的一个受关注部分即一个区间,用以标识一个上下文区间
P Span ID父区间ID,指一次逻辑流中前一个上下文的Span ID
ByteBuddy一个Java编码风格使用方式的字节码增强框架
轻量级代码增强所做的事情极其简单,基本不会增加额性能开销
日志跟踪在打印日志当中自动将以上三个跟踪ID打印出来,以便可以根据相应ID捞出对应的执行逻辑流相关的应用日志,快速辅助定位异常现场日志

1、Context

【上下文】,它是一个线程执行流中的一部分,例如:

  • HTTP IO线程的进入到退出
  • 一次MQ消息的消费到结束
  • 一个异步线程执行一次任务的开始到结束
  • 一次定时任务的开始到结束

2、链路跟踪ID

  • 需要一个全局跟踪ID串联所有上下文:X-Ato-Trace-Id
    • 可通过HTTP请求头传递或响应头返回
  • 需要一个ID标识本上下文的一次处理:X-Ato-Span-Id
    • 可通过HTTP请求头传递或响应头返回
  • 需要记录前一个上下文的标识ID:X-Ato-P-Span-Id
    • 可通过HTTP响应头返回
  • 可通过slf4j的MDC获取当前上下文的跟踪ID:
    • 当通过MDC.get("X-Ato-Span-Id")时返回当前上下文的 Span Id
    • 当通过MDC.get("X-Ato-P-Span-Id")时返回当前上下文的 Parent Span Id
    • 当通过MDC.get("X-Ato-Trace-Id")时返回当前上下文的 Trace Id

a、Trace ID

以【X-Ato-Trace-Id】取名标识,在【起始】上下文开始时若不存在则生成并设置一个,并且在进入下一个上下文时传入。起始上下文如:服务端HTTP IO请求上下文(不带该请求头取不到值时生成)、定时任务上下文等;而异步线程任务上下文通常由其他上下文发起,它是一个中间上下文。

b、Span ID

以【X-Ato-Span-Id】取名标识,在每个上下文开始时生成,唯一标记该上下文,在转入下一个上下文时传入,作为下一个上下文的【X-Ato-P-Span-Id】。

c、Parent Span ID

以【X-Ato-P-Span-Id】取名标识,由上一个上下文以其【X-Ato-Span-Id】传入;用以标记上一个上下文。

3、上下文的流转

例如,每一个[ ] 是一个或一组上下文,上下文流转时携带或生成对应的ID:

                                                                             <X-Ato-Trace-Id>
                                              /-----> [Send HTTP with header <X-Ato-Span-Id>   ]
                                             /                               <X-Ato-P-Span-Id>
             <X-Ato-Trace-Id>               /
[APP] <----> <X-Ato-Span-Id> <----> [HTTP IO] -------> [Async Thread]
             <X-Ato-P-Span-Id>              \ 
                                             \                             <X-Ato-Trace-Id>
                                              \-----> [Send MQ with header <X-Ato-Span-Id>   ]
                                                                           <X-Ato-P-Span-Id>

三、实现源码

Github

欢迎👏🏻大家一起来协作,让autotrace4j更加完善(参照已有组件新增并添加测试):

实现效果

  • 自动把ID注入日志:能自动识别输出格式并做注入

image.png

image.png

  • 请求响应头中自动注入返回跟踪Id:如果在请求时设置了X-Ato-Trace-Id请求头则本次请求的所有X-Ato-Trace-Id都是该值(通过这种方式跟客户端日志串联)

image.png

【本文在CSDN同时发布 blog.csdn.net/ichaser/art…

【关键词摘要】Java,Agent,ByteBuddy,Skywalking,日志跟踪,链路日志,链路跟踪,autotrace,autotrace4j