概述
增加请求日志,便于在开发阶段,追查错误,在将来上线后,进行线上问题的排查。
统一请求日志要完成以下功能:
- 记录时间、请求体和响应体;
- 记录应用特有的一些信息,如当前用户,客户端版本,请求处理时间等;
- 对于敏感信息,如登录密码,不做记录;
- 在开发阶段,日志打印到控制台,在服务器上运行阶段,将日志保存到文件;
- 保存在服务器的日志文件,按日切换文件,并将切出的旧文件压缩保存,并只保留指定一段时间的日志。
配置
应用配置文件
代码:
config/application-staging.yml。
spring:
  application:
    name: http-api-demo
  profiles:
    active: staging
logging:
  file: /kt/log/http-api-demo/http-api-demo.log
在应用配置文件里,配置日志文件保存目录,注意这里 spring.profiles.active 配置的是 staging 环境。
Logback 配置文件
代码:
src/main/resources/logback-spring.xml。
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <property name="LOG_FILE" value="${LOG_FILE:-${LOG_PATH:-${LOG_TEMP:-${java.io.tmpdir:-/tmp}}}/spring.log}"/>
    <springProfile name="default,dev">
        <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>
        <root level="INFO">
            <appender-ref ref="CONSOLE"/>
        </root>
        <logger name="org.springframework.jdbc.core" additivity="false" level="DEBUG" >
            <appender-ref ref="CONSOLE" />
        </logger>
    </springProfile>
    <springProfile name="staging,prod">
        <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
            <encoder>
                <pattern>${FILE_LOG_PATTERN}</pattern>
                <charset>UTF-8</charset>
            </encoder>
            <file>${LOG_FILE}</file>
            <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
                <fileNamePattern>${LOG_FILE}.a/%d{yyyyMMdd}.%i.log.gz</fileNamePattern>
                <maxHistory>180</maxHistory>
                <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                    <maxFileSize>100MB</maxFileSize>
                </timeBasedFileNamingAndTriggeringPolicy>
            </rollingPolicy>
        </appender>
        <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
            <appender-ref ref="FILE" />
        </appender>
        <root level="INFO">
            <appender-ref ref="ASYNC"/>
        </root>
    </springProfile>
</configuration>
这个配置文件是 Spring 框架对 Logback 配置文件的扩展,可以将多个 profile 的配置写到一个文件。
可以看到,如果是 default 或者 dev profile,输出到 CONSOLE;如果是 staging 或者 prod profile,输出到文件 ${LOG_FILE},这个 LOG_FILE 是个变量,就是我们之前在 application-staging.yml 中配置的 logging.file。
历史日志文件将保留 180 天,每个文件最大 100M,压缩后的文件名是 ${LOG_FILE}.a/%d{yyyyMMdd}.%i.log.gz,这里复用了 LOG_FILE 变量.
这相当于当前日志文件名是 /kt/log/http-api-demo/http-api-demo.log,历史文件保存在 /kt/log/http-api-demo/http-api-demo.log.a 目录里,文件名是 日期.序号.log.gz。
代码
日志相关代码不贴出来了,都在这里:
src/main/java/tech/jitao/httpapidemo/config/logging。
有几个要点:
- 日志记录使用的一些数据是 AuthInterceptor保存的,比如用户信息等;
- 为了实现跳过某些接口,在接口上标记 @NoLogging,并且可设定忽略请求或者响应,在LoggingInterceptor检测到需要忽略日志的请求,设置变量,在LoggingFilter中检测到忽略变量,进行忽略。因为标记是在Controller上,Filter检测不到,所以要多加一个Interceptor进行标记检测。
运行
如果想测试的效果,需要:
- 创建 /kt/log/http-api-demo目录,或修改成自己的,注意要全路径;
- 运行时,要指定配置文件全路径。
sudo mkdir -p /kt/log/http-api-demo
build/libs/http-api-demo-1.2.0.jar --spring.config.location=file:${项目目录全路径}/config/application-staging.yml
日志排查
记录的日志格式如下:
yyyy-MM-dd HH:mm:SS.sss  INFO 43746 --- [0.1-8080-exec-1] t.j.h.config.logging.LoggingFilter       : POST /app/account/login 200
<<<<<<<<<<
o= null
v= null
n= null
u= null
q= << omit >>
t= 4 ms
r= {"code":"OK","data":{"id":"6372534490252289024","name":"唐伯虎","avatar":"https://www.jitao.tech/static/flutter-logo.png","username":"tang","birthday":"2020-03-12","balance":"102.4","admin":"N","status":1,"lastLoginTime":"2020-03-12 14:22:09","createTime":"2020-03-12 14:22:09","updateTime":"2020-03-12 14:22:09","accessToken":"D8d8lKFtXdQ15Y5VoZm2UHQI8UZGGk17kArOFR7I"}}
>>>>>>>>>>
各字段意义:
- o,操作系统,来自 HTTP Header X-App-Os;
- v,客户端版本,来自 HTTP Header X-App-Version;
- n,客户端网络,来自 HTTP Header X-App-Network;
- u,用户 ID
- q,请求体
- t,处理时间,毫秒
- r,响应体
使用 Linux 的 awk cat grep head less sort tail wc 等命令配合管道进行日志排查。
简单举两个例子 🙋🌰🌰:
- 检查 ID 为 9527 的用户的登录日志
cat http-api-demo.log | grep -A 10 "POST /app/account/login" | grep -A 4 -B 6 "^u= 9527" | less
- 获取最慢的几个请求的处理时间,单位是毫秒:
cat http-api-demo.log | grep "^t=" | awk '{print $2}' | sort | tail
更多 Linux 命令,可以发动搜索引擎,一个参考文章:
总结
这种日志模式是针对小型应用的一个简单配置,如果是复杂的系统,日志一般会传到 ELK 之类的日志平台,属于高级用法,请自己搜索。
本文首发于微信公众号:肖念青,转载请保留原始出处信息。
我的个人网站:https://www.jitao.tech