微服务开发系列：如何打印好日志

源码地址

微服务开发系列：开篇
微服务开发系列：为什么选择 kotlin
微服务开发系列：为什么用 gradle 构建
微服务开发系列：目录结构，保持整洁的文件环境
微服务开发系列：服务发现，nacos 的小补充
微服务开发系列：怎样在框架中选择开源工具
微服务开发系列：数据库 orm 使用
微服务开发系列：如何打印好日志
微服务开发系列：鉴权
微服务开发系列：认识到序列化的重要性
微服务开发系列：设计一个统一的 http 接口内容形式
微服务开发系列：利用异常特性，把异常纳入框架管理之中
微服务开发系列：利用 knife4j，生成最适合微服务的文档

日志对一个系统来说是非常重要的。

我遇到过很多问题，找日志完全是无迹可寻，甚至前端很多请求发现十分耗时，最后一通查下来，都不知道时间到底耗在哪里，然后问题也无法复现了，只能通过不断的亡羊补牢加日志判断问题到底出在哪里。

虽然有 arthas 这样很有想法的工具，但是这种工具你不一定能用，一般是用来排查比较诡异的问题，还有就是时间很长了之后，很难通过 arthas 去还原出来当时的情况，而且就算你能还原，网络波动的问题能还原吗？

所以直接通过日志去排查是最好的，最直接方便，一般不会有人阻止你去看日志，作为一个开发人员，要想不加班，一定要多加日志。

当然添加日志也要合情合理，出现异常问题才去报告，日志要有规律有迹可循，控制日志的输出保持在合理的范围之内，有些开发人员的日志，多细节的东西都输出，结果造成了日志文件十分巨大，因此最好还是能只打印最有效的日志。

只打印最有效的日志，在不断测试的过程中优化对日志输入，不仅仅体现了对日志的重视，还能够帮助开发者在开发的过程中梳理逻辑思路，使表达更为通畅，并且在未来对这段代码优化重构时，也能加深自己的理解，重构出更优秀的模块。

1 日志输出

框架中的日志输出全都是使用日志文件，并没有使用带有第三方服务的日志框架，因为不想在多加任何服务了。

也没有使用任何数据库去记录日志，因为觉得文件就可以了，只要熟练运用 linux 的过滤命令，查问题是很快的。

2 框架日志配置

框架的日志使用的是 spring boot 本身的配置，并没有做类似用 spring-logback.xml 这种配置。

一个是因为觉得麻烦，还有一个就是 spring 提供的日志配置已经完全足够使用了。

日志的配置统一使用 nacos config 中配置的 logging.yml。

logging:
  pattern:
    console: '%clr(%d{${LOG_DATEFORMAT_PATTERN:yyyy-MM-dd HH:mm:ss.SSS}}){faint} %clr(${LOG_LEVEL_PATTERN:%5p}) %clr(${PID: }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint}%clr(%X{REQUEST_ID}){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:%wEx}'
    file: '%d{${LOG_DATEFORMAT_PATTERN:yyyy-MM-dd HH:mm:ss.SSS}} ${LOG_LEVEL_PATTERN:%5p} ${PID: } --- [%t] %-40.40logger{39} :%X{REQUEST_ID} %m%n${LOG_EXCEPTION_CONVERSION_WORD:%wEx}'
  file:
    name: ${SERVER_COMMON.BASE:${user.home}/server-common}/logs/server/${spring.application.name}/${spring.application.name}.log
    max-history: 20
    max-size: 50MB
  level:
    root: warn
    cn.framework: debug
    cn.gateway: debug
    cn.business: debug

里面的配置项，全都是 spring 自带的，该配置任何项目都必须引用，全部的日志路径都统一在一个位置。

3 日志打包格式

spring boot 默认的日志框架配置，日志在打包时，格式为 gz 格式，非常推荐这种格式。

使用 gz 的好处是，linux 包含了自带的 zgrep 命令可以直接搜索打包后的文件，如果你使用 zip 格式打包，那么在你想查找历史日志时，你必须把 zip 文件解压。

因此 gz 格式能很方便的让运维人员查找问题。

4 日志 pattern

上面的配置使用了 logging.pattern.console 和 logging.pattern.file 配置了日志的输出格式，直接拷贝过来的，除了多了一个 REQUEST_ID 的占位符，其它完全与原来的格式相同。

4.1 Request-Id

Request-Id  是 spring cloud gateway 给每个请求都产生的一个唯一 ID，类似于主键一样。

框架里面受到了这个的启发，把 Request-Id 传递给了两个地方

1. 下游系统
2. http response header 中

4.1.1 传到下游系统

传给下游系统就是为了让上面日志配置的占位符生效，具体的实现方式在 framework:cn.framework.config.logging.MvcLoggingConfigurer 类中。

这样配合 gateway:cn.gateway.framework.filter.LoggingFilter 就能把一个请求所有的日志都集齐了。

LoggingFilter.java 打印了一个请求最真实的耗时时间，从发起请求到返回结果，这样就能立马判断出一个请求耗时高到底是哪里出了问题。

MvcLoggingConfigurer.java 就让上面的占位符生效，只要是单线程打印的日志，都会带上 Request-Id，如果开发人员灵活一些，也能把 Request-Id 带上放在并发请求里面，更近一步打印 Request-Id+ThreadId，这样问题就很好查找了。

网关打印

下游系统打印

4.1.2 传到前端

这样的目的是，方便在前端使用接口处问题时，能够通过 network 请求中看到的 Request-Id，给到后端，里面查到所有相关的日志。

前端可以选择在判断请求出现问题时，就把 Request-Id 打印在 console 里面，这样不用等到再次打开 F12 浏览器控制台去复现错误，万一复现不出来就很有用了。

因为 console 的输出不会因为浏览器控制台的打开关闭而消失。

5 日志输出规范

在框架中打印日志，请尽量遵守下面几点：

1. 日志中不能使用中文，这是由于系统面临的环境是不可控的，随时可能让中文日志变成乱码，使用英文和数字是最稳妥的
2. 尽量不要使用过多符号，复杂过多的符号在生产环境并不能有效的提高阅读效率，反而造成 linux 下文件管道过滤时的麻烦
3. 一个重要的方法内尽量包含唯一标识，比如功能名称，这样过滤日志更方便
4. 谨慎选择输出日志，避免打印大量、重复的日志，造成空间浪费和排查困难

6 HTTP 请求耗时

gateway:cn.gateway.framework.filter.LoggingFilter 除了打印了所有请求的耗时，也将请求的耗时，传给了前端的 http response header 中，参数名是 Cost。

这样做有一个好处，就是前端在发现请求较慢时，就能通过 network 的请求耗时和 Cost 作对比，如果 network >> Cost，说明网络本身就慢。

前端最好在判断耗时过长时，把 Cost 打印在 F12 浏览器控制台中。

7 Log 对象生成

由于 kotlin 中不能再使用任何 lombok 的注解，因此 Log 变量也不能通过注解的方式直接生成。

于是经过了一段时间在网上的探索，有一种更加方便的获取 Log 变量的方式，实现在类 cn.vte.framework.common.log.Slf4k 中。

实现的逻辑是 kotlin 的变量扩展加上 reified 泛型固定，想要获取 Log 变量时，只需要引入即可。

Log 对象并不是使用的常规 Slf4jLog，而是使用的 [KotlinLogging](https://github.com/MicroUtils/kotlin-logging) 封装后的 Log，相比于一般 Log 对象，多支持了一些 kotlin 的特性。

8 http body 获取

框架中提供了一种获取 requestBody 和 responseBody 的方式。

能够在不影响请求流的情况下，获取的请求的 body。

实现方式参考了 spring cloud 的 ModifyResponseBodyGatewayFilterFactory 和 ModifyRequestBodyGatewayFilterFactory。

开启方式，是需要再 gateway 下的 bootstrap.yml 中，路由配置下增加 filter。

在 LoggingFilter 中，虽然获取到了，但是并没有打印，如果有需要可以自行打印出来。

网关打印请求的完整结果