概述

增加請求日志，便于在開發(fā)階段，追查錯誤，在將來上線后，進(jìn)行線上問題的排查。

統(tǒng)一請求日志要完成以下功能：

• 記錄時間、請求體和響應(yīng)體；
• 記錄應(yīng)用特有的一些信息，如當(dāng)前用戶，客戶端版本，請求處理時間等；
• 對于敏感信息，如登錄密碼，不做記錄；
• 在開發(fā)階段，日志打印到控制臺，在服務(wù)器上運(yùn)行階段，將日志保存到文件；
• 保存在服務(wù)器的日志文件，按日切換文件，并將切出的舊文件壓縮保存，并只保留指定一段時間的日志。

配置

應(yīng)用配置文件

代碼：

config/application-staging.yml。

spring:
  application:
    name: http-api-demo
  profiles:
    active: staging

logging:
  file: /kt/log/http-api-demo/http-api-demo.log

在應(yīng)用配置文件里，配置日志文件保存目錄，注意這里 spring.profiles.active 配置的是 staging 環(huán)境。

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 配置文件的擴(kuò)展，可以將多個 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，這里復(fù)用了 LOG_FILE 變量.

這相當(dāng)于當(dāng)前日志文件名是 /kt/log/http-api-demo/http-api-demo.log，歷史文件保存在 /kt/log/http-api-demo/http-api-demo.log.a 目錄里，文件名是 日期.序號.log.gz。

代碼

日志相關(guān)代碼不貼出來了，都在這里：

src/main/java/tech/jitao/httpapidemo/config/logging。

有幾個要點(diǎn)：

• 日志記錄使用的一些數(shù)據(jù)是 AuthInterceptor 保存的，比如用戶信息等；
• 為了實(shí)現(xiàn)跳過某些接口，在接口上標(biāo)記 @NoLogging，并且可設(shè)定忽略請求或者響應(yīng)，在 LoggingInterceptor 檢測到需要忽略日志的請求，設(shè)置變量，在 LoggingFilter 中檢測到忽略變量，進(jìn)行忽略。因?yàn)闃?biāo)記是在 Controller 上，Filter 檢測不到，所以要多加一個 Interceptor 進(jìn)行標(biāo)記檢測。

運(yùn)行

如果想測試的效果，需要：

• 創(chuàng)建 /kt/log/http-api-demo 目錄，或修改成自己的，注意要全路徑；
• 運(yùn)行時，要指定配置文件全路徑。

sudo mkdir -p /kt/log/http-api-demo
build/libs/http-api-demo-1.2.0.jar --spring.config.location=file:${項(xiàng)目目錄全路徑}/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，操作系統(tǒng)，來自 HTTP Header X-App-Os；
• v，客戶端版本，來自 HTTP Header X-App-Version；
• n，客戶端網(wǎng)絡(luò)，來自 HTTP Header X-App-Network；
• u，用戶 ID
• q，請求體
• t，處理時間，毫秒
• r，響應(yīng)體

使用 Linux 的 awk cat grep head less sort tail wc 等命令配合管道進(jìn)行日志排查。

簡單舉兩個例子 ??????：

• 檢查 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 命令，可以發(fā)動搜索引擎，一個參考文章：

你需要熟練運(yùn)用的 12 個命令行工具。

總結(jié)

這種日志模式是針對小型應(yīng)用的一個簡單配置，如果是復(fù)雜的系統(tǒng)，日志一般會傳到 ELK 之類的日志平臺，屬于高級用法，請自己搜索。

本文首發(fā)于微信公眾號：肖念青，轉(zhuǎn)載請保留原始出處信息。

我的個人網(wǎng)站：https://www.jitao.tech