日志追踪系统设计

# 解决的问题

1. 了解线上系统的运行状态
2. 快速准确定位线上问题
3. 发现系统瓶颈
4. 预警系统潜在风险
5. 挖掘产品最大价值

##日志的分类

1. 诊断日志, 典型的有:
   • 请求入口和出口
   • 外部服务调用和返回
   • 资源消耗操作: 如读写文件等
   • 容错行为: 如云硬盘的副本修复操作
   • 程序异常: 如数据库无法连接
   • 后台操作: 定期执行删除的线程
   • 启动、关闭、配置加载
2. 统计日志:
   • 用户访问统计: 用户 IP、上传下载的数据量, 请求耗时等
   • 计费日志（如记录用户使用的网络资源或磁盘占用, 格式较为严格, 便于统计）
3. 审计日志:
   • 管理操作 对于简单的系统, 可以将所有的日志输出到同一个日志文件中, 并通过不同的关键字进行区分. 而对于复杂的系统, 将不同需求的日志输出到不同的日志文件中是必要的, 通过对不同类型的文件采用不同的日志格式
4. 业务日志

# 分布式日志系统的设计

# 日志采集器

负责把业务系统的方法调用栈和远程服务调用信息从业务系统中传递给处理器

实现方式有:

1. 应用层编写代码主动推送
2. AOP 拦截
3. JavaAgent 字节码增强

问题: 这里推送给采集器的日志是统一格式的日志, 并非我们自己写的 log 输出, 自己写的 log 输出可以通过 appender 输出给 logstash.

# 生成调用链 ID

一个系统通常通过 traceId 来对请求进行唯一的标记, 目的是可以通过 traceId 将一个请求在系统中的执行过程串联起来. 该 traceId 通常会随着响应返回给调用者, 如果调用出现问题, 调用者也可以通过提供 traceId 帮助服务提供者定位问题.

# 传递调用链信息

前面生成的 traceId 传递到下一级调用, 从而将调用信息关联起来.

这里分为5种传递方式:

1. Java 进程内传递
2. 服务间传递
3. 主子线程间传递
4. 消息队列的传递
5. 缓存, 数据库访问

# Java 进程内传递

在 Java 应用系统中, 通过 ThreadLocal 来传递 TraceId 和 spanId

# 服务间传递

在服务间通过 RPC 传递

使用 com.alibaba.dubbo.rpc.RpcInvocation 的 setAttachment 和 getAttachment 来设置和获取自定义上下文数据

# 主子线程间传递

将一些耗时或者非核心业务通过异步线程处理, 如果要跟踪这部分调用链,则需要在创建子线程时,将 traceId 和 spanId 一起传递过去,并放在子线程的 ThreadLocal 中.

具体是使用 ThreadLocal 的子类 InheritableThreadLocal, 通过这个组件可以实现父子线程之间的数据传递, 在子线程中能够父线程中的 ThreadLocal 本地变量.

但对于使用线程池等会池化复用线程的组件的情况, 线程由线程池创建好, 并且线程是池化起来反复使用的； 这时父子线程关系的 ThreadLocal 值传递已经没有意义, 应用需要的实际上是把任务提交给线程池时的 ThreadLocal 值传递到任务执行时.

这里使用阿里开源的 transmittable-thread-local.

# 消息队列的传递

对 kafka 消息队列的跟踪

1. 发送消息时, 手工添加 traceId 和 spanId
2. 修改 kafka 源码, 在每次发送消息时,将 traceId 和 spanId 增加到消息报文中, 在消息队列的处理端的库中先解析报文, 再讲业务报文传递给业务层处理.

# 缓存, 数据库访问

封装缓存,数据库的客户端, 将 traceId 和 spanId 与访问的数据进行关联

# 采集率设置

因为 QPS 越高, 需要生成的调用日志也就越高. 因此, 为了降低整体的输出数据量, 根据 traceId 中的顺序数进行采样, 提供了多种采样策略搭配:

• 100% 采样: 它会对业务带来影响, 因此最好内置支持客户端自动降级；
• 固定阈值采样: 全局或租户内统一控制；
• 限速采样: 在入口处按固定频率采样若干条调用链；
• 异常优先采样: 调用出错时优先采样；
• 个性化采样: 按用户 ID、入口 IP、应用、调用链入口、业务标识等配置开启采样.

通过上面这五种采样策略的搭配使用, 可以灵活地控制调用链上数据的输出, 确保数据量不会过大.

# 日志处理器

负责从业务系统的采集器中接收服务调用信息并聚合调用链, 将其存储在分布式数据存储中, 以及对调用链进行分析, 并输出给监控和报警系统.

聚合调用链信息, 从中发现调用的问题, 如:

1. 抛出异常
2. 调用超时
3. 统计调用次数等
4. 发送报警短信, 邮件, 微信信息等

# 日志存储和搜索

存储海量的调用链数据, 并支持灵活的查询和搜索功能

# 关联业务 Id

在业务日志中记录 traceId、业务事件 id 等信息, 从而建立调用链与业务事件日志的关联, 通过业务 Id 反查 traceId, 获取更多的上下文信息

一个兑吧订单（order_234325123124）发现存在问题, 我们可以根据订单号查到与之绑定的 traceId, 根据 traceId 不仅可以查看系统调用的事件, 还可以看到与业务相关的事件, 如用户积分情况等, 也就是说根据业务 Id 可以在调用链上查看兑吧商品, 用户积分以及扣除积分等信息, 大大提升错误排查速度.

# 日志展示系统

支持查询调用链, 业务链等功能

为了更直观的查看调用链信息, 需要一个前端展示页面

# 监控和报警

通过定时的在日志存储和搜索系统中查找服务和某一标准的数据指标, 然后与设置的阈值对比, 如果超出阈值, 则通过短信,邮件或微信来报警

# 日志系统优化和最佳实践

1. 打印日志的最佳时机
2. 日志级别设置
3. 日志的数量和大小
4. 日志的切割方式
5. 日志格式设置

# 日志级别设置

• QA 环境使用 debug 及以下级别日志
• 刚刚上线的引用还没到稳定期, 使用 debug 级别的日志
• 上线稳定后使用 info 级别的日志
• 常年稳定不出问题的应用使用 error 级别的日志
• 选择一台机器开启 DEBUG 级别的日志, 在线上任何问题的时候, 都可以通过日志最快的找到问题的根源.

# 日志级别的使用

对于日志级别的分类, 有以下参考:

• FATAL

  表示需要立即被处理的系统级错误. 当该错误发生时, 表示服务已经出现了某种程度的不可用, 系统管理员需要立即介入. 这属于最严重的日志级别, 因此该日志级别必须慎用, 如果这种级别的日志经常出现, 则该日志也失去了意义. 通常情况下, 一个进程的生命周期中应该只记录一次 FATAL 级别的日志, 即该进程遇到无法恢复的错误而退出时. 当然, 如果某个系统的子系统遇到了不可恢复的错误, 那该子系统的调用方也可以记入 FATAL 级别日志, 以便通过日志报警提醒系统管理员修复；

• ERROR

  该级别的错误也需要马上被处理, 但是紧急程度要低于 FATAL 级别. 当 ERROR 错误发生时, 已经影响了用户的正常访问. 从该意义上来说, 实际上 ERROR 错误和 FATAL 错误对用户的影响是相当的. FATAL 相当于服务已经挂了, 而 ERROR 相当于好死不如赖活着, 然而活着却无法提供正常的服务, 只能不断地打印 ERROR 日志. 特别需要注意的是, ERROR 和 FATAL 都属于服务器自己的异常, 是需要马上得到人工介入并处理的. 而对于用户自己操作不当, 如请求参数错误等等, 是绝对不应该记为 ERROR 日志的；

• WARN

  该日志表示系统可能出现问题, 也可能没有, 这种情况如网络的波动等. 对于那些目前还不是错误, 然而不及时处理也会变为错误的情况, 也可以记为 WARN 日志, 例如一个存储系统的磁盘使用量超过阈值, 或者系统中某个用户的存储配额快用完等等. 对于 WARN 级别的日志, 虽然不需要系统管理员马上处理, 也是需要及时查看并处理的. 因此此种级别的日志也不应太多, 能不打 WARN 级别的日志, 就尽量不要打；

• INFO

  该种日志记录系统的正常运行状态, 例如某个子系统的初始化, 某个请求的成功执行等等. 通过查看 INFO 级别的日志, 可以很快地对系统中出现的 WARN,ERROR,FATAL 错误进行定位. INFO 日志不宜过多, 通常情况下, INFO 级别的日志应该不大于 TRACE 日志的 10%；

• DEBUG or TRACE

  这两种日志具体的规范应该由项目组自己定义, 该级别日志的主要作用是对系统每一步的运行状态进行精确的记录. 通过该种日志, 可以查看某一个操作每一步的执 行过程, 可以准确定位是何种操作, 何种参数, 何种顺序导致了某种错误的发生. 可以保证在不重现错误的情况下, 也可以通过 DEBUG（或 TRACE）级别的日志对问题进行诊断. 需要注意的是, DEBUG 日志也需要规范日志格式, 应该保证除了记录日志的开发人员自己外, 其他的如运维, 测试人员等也可以通过 DEBUG（或 TRACE）日志来定位问题；

# 日志数量和大小

控制日志的输出量, 避免由于业务量大而导致服务器磁盘大量输出无用的日志而被占满

• 只打印关键信息, 不要随便把对象 Json 序列化后打印出来
• 单条日志不能超过 1K
• 定时任务删除之前的日志 (logback maxHistory属性设置)

# 切割方式

• 使用日志框架自带的 Appender 将日志按照日期进行切割(不同系统根据业务量设置不同的日志切割方式)
• 将不同级别的日志输出到不同文件中.

# 日志格式的配置

1. 发生时间
2. 日志级别 (DEBUG,INFO,WARN,ERROR,FATAL)
3. 日志输出标记
4. 线程标识
5. 文件名称 (DEBUG 日志需要, 非 DEBUG 日志可以为空)
6. 文件行号 (DEBUG 日志需要, 非 DEBUG 日志可以为空)
7. 函数名称 (DEBUG 日志需要, 非 DEBUG 日志可以为空)
8. 日志描述

# 开发人员的日志意识

不管是通过 AOP 还是 Filter 来采集日志, 都是按照统一的格式来输出日志, 是为了更好的聚合这些日志, 方便查询. 而在程序中难免需要我们手动添加一些日志, 来调试代码或者在重要的业务中输出信息等, 我们也必须按照统一的格式打印日志, 方便搜索.

1. 统一的日志格式
2. 使用占位符的方式打印日志
3. 使用 MDC