微服务应用性能分析实战13 结构化日志：如何规范数千开发的应用日志？

办公模板库素材蛙

已于 2022-09-24 13:16:23 修改

阅读量704

点赞数 1

分类专栏： java 教程文章标签：微服务 ELK APM

于 2022-09-24 13:16:04 首次发布

本文链接：https://blog.csdn.net/fegus/article/details/127024053

版权

教程同时被 2 个专栏收录

1193 篇文章 259 订阅

订阅专栏

java

564 篇文章 141 订阅

订阅专栏

本文介绍了结构化日志在解决线上问题中的重要性，通过实例展示了如何将原始日志转换为结构化日志，以提高问题定位和排查的效率。文中提出了框架日志矩阵法来确保日志的完整性和规范性，并介绍了日志码的概念，用于优化业务日志。此外，还讨论了异步日志框架与分布式链路集成的挑战和解决方案，强调了日志规范化的价值和实践策略。

摘要由CSDN通过智能技术生成

在无法远程调试和网络环境隔离等条件下，应用日志可以说是我们追查线上各种疑难杂症的第一手资料。

好的日志（或是日志埋点）衍生出的 APM 系统，可以让我们具备一种“洞察力”，即先于用户发现问题、定位问题、解决问题；而无规范的应用日志，则会让线上日志五花八门，严重降低线上第一手资料的质量。

从“低头写日志代码”到“抬头写日志”，对于每个 RD 来说，这是一种势在必行的改变。这里“抬头写日志”，意思是写出的日志能更好地融入 APM 生态，并更符合日志规范。这样在定位问题时，才能根据日志做到有的放矢，笃定而行。

所以这一讲，我将以用户订单下单的业务场景为例，教你如何将原始日志改造为结构化日志，并与你分享日志规范化在融入 APM 生态时的踩坑故事与心得经验。其中，框架日志矩阵法和日志码是重点，它们是最能规范数千 RD 编写应用日志的技术手段。

为什么需要结构化日志？

在项目迭代过程中，我们会在代码的必要位置打印日志。比如订单系统，我们会在用户下单的核心代码块，增加 try-catch 去捕获下单逻辑的异常；并在 catch 代码块中，使用 LOGGER.error 方法记录异常日志。

当 RD 上线忘记创建线上表的时候，异常日志是这样的：

timestamp [thread-id] ERROR Class - Table 'local.dual_1' doesn't exist

1.结构化日志前

起初，我们会将 ERROR 类型的日志单独放在一个日志文件中，然后通过脚本监听 ERROR 日志文件的增量；当 ERROR 增加时，触发报警；随后 RD 登录堡垒机去搜索日志，从而定位问题。如果公司有安全审计的规范，还要填写工单，拜托 OP（运维专员）去帮忙日志脱敏后下载到本地，才能开始定位问题。

总体来说，这个流程十分原始。

为了解决这个问题，我们会引入 APM 项目 ELK 来处理和分析日志。ELK 具备可视化日志功能，团队成员在接收报警后，只需要登录 ELK，就都可以看到异常日志。

但是，针对上面的 Case，如果不对日志进行改造，贸然引入 ELK，不仅无法发挥出 ELK 的能力，还会带来更多问题。

这个异常日志是由什么应用服务打印的？以及应用的负责人是谁？
日志看不懂，找开发的 RD 时，不知道如何快速对齐解决问题的单点瓶颈。
日志记不全，不知道引起异常的 SQL 是什么，以及 DB 集群是哪个。
……

2.结构化日志后

我们的解决办法是将原来的原始日志改造为结构化日志。顾名思义，结构化日志，即日志是具有结构的。以上面 CASE 的改造为例，结构化后的日志为：

{ 
   "application_id": "order", 
   "log_type": "mysql_fail", 
   "trace_id": "snow_001", 
   "error_msg": "Table 'local.dual_1' doesn't exist", 
   "sql": "select 'str' from dual_1", 
   "latency": "10", 
   "local_ip":"127.0.0.1", 
   "remote_ip":"localhost", 
   "remote_port":"3306", 
   "db_name": "local" 
}

结构化日志可以让团队所有人快速拉齐信息水平，ELK 中展示的异常日志，便很容易被理解：

异常日志（error_msg）"Table 'local.dual_1' doesn't exist" 是由应用（application_id）订单系统（order）引起的；
应用节点（local_ip）127.0.0.1 使用 SQL"select 'str' from dual_1" 调用localhost:3306（remote_ip:remote_port）集群；
可以使用全局链路 ID（trace_id）snow_001 来跟踪此异常对上下游造成的影响。

你看，日志经过结构化处理，不仅可以降低沟通成本，还能提高每个人对问题的认知，最终帮助定位问题提效。

如何将原始日志改造为结构化日志？

首先我们看上面的 Case，结构化日志就是以 JSON 为结构输出，结构化后的日志会更亲和 ELK 的处理和分析。

以用户订单下单的业务场景为例，如下图所示。

App：用户通过手机 App 进行下单请求，会在 App 上生成相应的埋点日志。
Nginx：请求经过 Nginx 会记录访问日志，然后根据请求的路由规则，专访到相应的应用服务器。
应用服务：应用服务器 HTTP 框架记录本次请求的分析信息；下单代码块会记录本次请求在代码块中的运行过程；ORM 框架日志会记录本次操作引起的数据变更。

用户下单业务场景流程图

接下来，我会根据订单服务用户下订单的场景，来详细讲述结构化日志应该如何拆分，以及拆分后的每种日志又是如何实现结构化的。

1.日志的拆分

用户通过手机 App 进行下单操作，引发的日志会拆分为“用户下单业务场景流程图”中所示的那 5 类：

用户操作行为的埋点日志
Nginx 路由请求的日志
HTTP 框架接口提供者日志
核心业务下单日志
ORM 框架操作数据库日志

可以看出，日志的拆分就是把不同作用的日志，存储到相应的日志文件里面。

拆分带来的好处是在我们定位线上问题的时候就会清晰很多：

比如，我们在进行数据库的性能分析时，可以以 ORM 框架操作数据库的日志为根据；
然后，再通过进程 ID、TraceID 或是毫秒级的时间戳，关联到核心业务日志；
接着，通过 HTTP 框架接口提供者日志和 Nginx 路由请求的日志，查询出返回给调用者的信息是什么；
最后，根据用户操作行为的埋点日志解决线上问题。

在这样的拆分过程中，我们将日志分为了 5 类；而对于这 5 类日志，我们又可以从编写日志的用户角度将其分为两类：

基础架构组 RD 编写的框架日志
负责应用迭代 RD 编写的业务日志

接下来我展开讲解一下。

2.框架日志

对于用户通过手机 App 进行下单操作已发的上述 5 类日志，其中：

用户操作行为的埋点日志
Nginx 路由请求的日志
HTTP 框架接口提供者日志
ORM 框架操作数据库日志

这 4 类属于框架日志，它们一般由基础架构 RD 负责完成。

在开发过程中，如果项目组内每个开发人员都能编写风格统一的日志，那么在运维处理问题时，就非常容易让每个人都参与进来，将力量拧成一股绳；反之，则各自为战。

那如何将日志风格统一呢？就需要让每个场景的日志都具备这个场景的标准属性，就像表达方式中的“主谓宾定状补”一样，一句话便拆分出明确意义的属性。这样在理解时，就可以更精准、有目的性地知道主语是谁、谓语是哪个。

接下来，我们看一下如何做到让结构化框架日志的每个日志属性都有意义，让其关键信息尽可能少遗漏呢？你可以使用日志矩阵法，去梳理框架日志是否全备。

【框架日志矩阵法】

通过矩阵法可以评估和决策日志框架记录得是否符合预期，以 HTTP 框架和 ORM 框架为例：

Y 代表需要任何情况都需要记录该字段；
O 代表需要在特定的情况下无须人为介入，会记录该字段，如发生慢查；
D 代表需要在动态开启 DEBUG 时，记录该字段；
橙色代表从系统资源中获取；
黄色代表从框架对象中获取。

框架日志矩阵法，可以清晰地让原始日志变为规范的结构化日志：

定位问题时，明确结构化日志中 JSON 每个属性的作用；
定位问题后，我们需要及时复盘结构化框架日志的属性是否有缺失，若有缺失需及时复盘和迭代框架日志矩阵。

3.业务日志

在刚刚介绍 5 大类日志中，除 4 大框架日志外，被“落单”的核心业务下单日志，就是接下来我要讲解的业务日志了，它由负责应用迭代的 RD 完成。

以我的实践经验，100 行的业务代码，至少会有 1 处关键业务日志。当项目迭代 2 年以上，代码量超过 10 万行时，那项目就至少会有 1000 处关键业务日志。

当线上出现问题时，RD 会根据业务日志现场，也就是核心业务日志去翻看代码，然后从代码视角来解释现场。当项目的交接和新人的加入时，新接手项目的 RD 会逐渐对原始日志产生理解偏差，所以这种方式也不友好、高效。具体原因如下：

时效低，因为没有使用日志码；
由于代码编写的风格不同，RD 也很难理解前人写的原始代码。

而如果我们使用日志码和异常规范，就可以从原始作者视角来解释日志，并且可以形成业务日志资产。

【日志码】

日志码就是在 RD 定义核心日志时，需要对日志信息指定相应的日志码。日志码的指定，解决了代码的日志信息不能书写很多，且需要上线才能完成迭代等问题。

当日志信息指定了日志码后，日志信息的角色是简单的代码逻辑阐述。

比如，[A0001] 用户 uid:001 下单失败的原因，账户已被冻结。那我们根据标准的日志码，定义更详细的日志信息和线上问题跟进手册。
再比如，日志码 A0001 首次上线时，原始开发成员对 A0001 日志码进行解释，随着项目的运行，值班成员只需对 A0001 相关的工单进行关联。这样向上出现问题时，我们就可以通过日志码快速解决线上问题。

这里给你几个日志码指定时的建议。

以目前国内微服务化和中台化的应用形态，3~5 年项目就会重构，代码至多有几十万行为依据，日志码可以有首位 1 个字母 + 4 个数字组成。首字母代表应用系统代码块的业务类型，递增数字代表日志码的增量。
日志码的指定可以解决线上日志的可追溯性问题，降低沟通成本。所以项目的日志码字典最好在项目初期就建立，并且业务日志相关的代码块迭代时，以及值班发现相关代码块出现问题时，都要对日志码进行迭代，这样才能发挥出日志码的价值。
日志码字典的维护，应该面向可量化监控设计。比如 A0001 代表用户下单时，资金冻结。那当 A0001 日志码超过一定量时，是否可以预测出相关联的上下游系统需要做出的必要调整动作。