Spring Cloud 升級之路 - 2020.0.x - 3. Undertow 的 accesslog 配置

乾貨滿滿張雜湊 發表於 2021-04-08

上一節我們講述瞭如何使用 Undertow 作為我們的 Web 服務容器,本小節我們來分析使用 Undertow 的另一個問題,也就是如何配置 accesslog,以及 accesslog 的各種佔位符。

accesslog 相關配置

server:
  undertow:
    # access log相關配置
    accesslog:
      # 存放目錄,預設為 logs
      dir: ./log
      # 是否開啟
      enabled: true
      # 格式,各種佔位符後面會詳細說明
      pattern: '{
                  "transportProtocol":"%{TRANSPORT_PROTOCOL}",
                  "scheme":"%{SCHEME}",
                  "protocol":"%{PROTOCOL}",
                  "method":"%{METHOD}",
                  "reqHeaderUserAgent":"%{i,User-Agent}",
                  "cookieUserId": "%{c,userId}",
                  "queryTest": "%{q,test}",
                  "queryString": "%q",
                  "relativePath": "%R, %{REQUEST_PATH}, %{RESOLVED_PATH}",
                  "requestLine": "%r",
                  "uri": "%U",
                  "thread": "%I",
                  "hostPort": "%{HOST_AND_PORT}",
                  "localIp": "%A",
                  "localPort": "%p",
                  "localServerName": "%v",
                  "remoteIp": "%a",
                  "remoteHost": "%h",
                  "bytesSent": "%b",
                  "time":"%{time,yyyy-MM-dd HH:mm:ss.S}",
                  "status":"%s",
                  "reason":"%{RESPONSE_REASON_PHRASE}",
                  "respHeaderUserSession":"%{o,userSession}",
                  "respCookieUserId":"%{resp-cookie,userId}",
                  "timeUsed":"%Dms, %Ts, %{RESPONSE_TIME}ms, %{RESPONSE_TIME_MICROS} us, %{RESPONSE_TIME_NANOS} ns",
                }'
      # 檔案字首,預設為 access_log
      prefix: access.
      # 檔案字尾,預設為 log
      suffix: log
      # 是否另起日誌檔案寫 access log,預設為 true
      # 目前只能按照日期進行 rotate,一天一個日誌檔案
      rotate: true

注意點 1:日誌檔案 rotate 目前只能按照日期

Undertow 的 accesslog 處理核心類抽象是 io.undertow.server.handlers.accesslog.AccesslogReceiver。由於目前 Undertow 的 AccesslogReceiver 只有一種實現在使用,也就是 io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver

檢視 DefaultAccessLogReceiver 的 rotate 時機:

DefaultAccessLogReceiver

/**
 * 計算 rotate 時間點
 */
private void calculateChangeOverPoint() {
    Calendar calendar = Calendar.getInstance();
    calendar.set(Calendar.SECOND, 0);
    calendar.set(Calendar.MINUTE, 0);
    calendar.set(Calendar.HOUR_OF_DAY, 0);
    //當前時間日期 + 1,即下一天
    calendar.add(Calendar.DATE, 1);
    SimpleDateFormat df = new SimpleDateFormat("yyyy-MM-dd", Locale.US);
    currentDateString = df.format(new Date());
    // if there is an existing default log file, use the date last modified instead of the current date
    if (Files.exists(defaultLogFile)) {
        try {
            currentDateString = df.format(new Date(Files.getLastModifiedTime(defaultLogFile).toMillis()));
        } catch(IOException e){
            // ignore. use the current date if exception happens.
        }
    }
    //rotate 時機是下一天的 0 點
    changeOverPoint = calendar.getTimeInMillis();
}

accesslog 佔位符

其實 Undertow 中的 accesslog 佔位符,就是之前我們提到的 Undertow Listener 解析請求後抽象的 HTTP server exchange 的屬性。

官網文件的表格並不是最全的,並且注意點並沒有說明,例如某些佔位符必須開啟某些 Undertow 特性才能使用等等。這裡我們列出下。

首先先提出一個注意點,引數佔位符,例如 %{i,你要看的header值} 檢視 header 的某個 key 的值。逗號後面注意不要有空格,因為這個空格會算入 key 裡面導致拿不到你想要的 key

請求相關屬性

描述 縮寫佔位符 全名佔位符 引數佔位符 原始碼
請求傳輸協議,等價於請求協議 %{TRANSPORT_PROTOCOL} TransportProtocolAttribute
請求模式,例如 http、https 等 %{SCHEME} RequestSchemeAttribute
請求協議,例如 HTTP/1.1 %H %{PROTOCOL} RequestProtocolAttribute
請求方法,例如 GET、POST 等 %m %{METHOD} RequestMethodAttribute
請求 Header 的某一個值 %{i,你要看的header值} RequestHeaderAttribute
Cookie 的某一個值 %{c,你要看的cookie值} 或者 %{req-cookie,你要看的cookie值} 分別對應 CookieAttributeRequestCookieAttribute
路徑引數 PathVariable 由於並沒有被 Undertow 的 Listener 或者 Handler 解析處理,所以攔截不到,無法確認是否是一個 PathVariable 還是就是 url 路徑。所以,PathVariable 的佔位符是不會起作用的 %{p, 你想檢視的路徑引數 key } PathParameterAttribute
請求引數,即 url 的 ? 之後鍵值對,這裡可以選擇檢視某個 key 的值。 %{q, 你想檢視的請求引數 key} QueryParameterAttribute
請求引數字串,即 url 的 ? 之後的所有字元} %q(不包含 ?) %{QUERY_STRING}(不包含 ?);%{BARE_QUERY_STRING}(包含 ?) QueryStringAttribute
請求相對路徑(在 Spring Boot 環境下,大多數情況 RequestPath 和 RelativePath 還有 ResolvedPath 是等價的),即除去 host,port,請求引數字串的路徑 %R %{RELATIVE_PATH} 或者 %{REQUEST_PATH} 或者 %{RESOLVED_PATH} 分別對應 RelativePathAttributeRequestPathAttributeResolvedPathAttribute
請求整體字串,包括請求方法,請求相對路徑,請求引數字串,請求協議,例如 Get /test?a=b HTTP/1.1 %r %{REQUEST_LINE} RequestLineAttribute
請求 URI,包括請求相對路徑,請求引數字串 %U %{REQUEST_URL} RequestURLAttribute
處理請求的執行緒 %I %{THREAD_NAME} ThreadNameAttribute

注意:

  1. 路徑引數 PathVariable 由於並沒有被 Undertow 的 Listener 或者 Handler 解析處理,所以攔截不到,無法確認是否是一個 PathVariable 還是就是 url 路徑。所以,PathVariable 的佔位符是不會起作用的

請求地址相關

描述 縮寫佔位符 全名佔位符 引數佔位符 原始碼
host 和 port,一般就是 HTTP 請求 Header 中的 Host 值,如果 Host 為空則獲取本地地址和埠,如果沒獲取到埠則根據協議用預設埠(http:80,,https:443) %{HOST_AND_PORT} HostAndPortAttribute
請求本地地址 IP %A %{LOCAL_IP} LocalIPAttribute
請求本地埠 Port %p %{LOCAL_PORT} LocalPortAttribute
請求本地主機名,一般就是 HTTP 請求 Header 中的 Host 值,如果 Host 為空則獲取本地地址 %v %{LOCAL_SERVER_NAME} LocalServerNameAttribute
請求遠端主機名,通過連線獲取遠端的主機地址 %h %{REMOTE_HOST} RemoteHostAttribute
請求遠端 IP,通過連線獲取遠端的 IP %a %{REMOTE_IP} RemoteIPAttribute

注意:

  1. 請求的遠端地址我們一般不從請求連線獲取,而是通過 Http Header 裡面的 X-forwarded-for 或者 X-real-ip 等獲取,因為現在請求都是通過各種 VPN,負載均衡器發上來的。

響應相關屬性

描述 縮寫佔位符 全名佔位符 引數佔位符 原始碼
傳送的位元組數大小,除了 Http Header 以外 %b (如果為空就是 -) 或者 %B (如果為空就是 0) %{BYTES_SENT} (如果為空就是 0) BytesSentAttribute
accesslog 時間,這個不是收到請求的時間,而是響應的時間 %t %{DATE_TIME} %{time, 你自定義的 java 中 SimpleDateFormat 的格式} DateTimeAttribute
HTTP 響應狀態碼 %s %{RESPONSE_CODE} ResponseCodeAttribute
HTTP 響應原因 %{RESPONSE_REASON_PHRASE} ResponseReasonPhraseAttribute
響應 Header 的某一個值 %{o,你要看的header值} ResponseHeaderAttribute
響應 Cookie 的某一個值 %{resp-cookie,你要看的cookie值} ResponseCookieAttribute
響應時間,預設 undertow 沒有開啟請求時間內統計,需要開啟才能統計響應時間 %D(毫秒,例如 56 代表 56ms) %T(秒,例如 5.067 代表 5.067 秒) %{RESPONSE_TIME}(等價於 %D) %{RESPONSE_TIME_MICROS} (微秒) %{RESPONSE_TIME_NANOS}(納秒) ResponseTimeAttribute

注意:預設 undertow 沒有開啟請求時間內統計,需要開啟才能統計響應時間,如何開啟呢?通過註冊一個 WebServerFactoryCustomizer 到 Spring ApplicationContext 中即可。請看下面的程式碼(專案地址:https://github.com/HashZhang/spring-cloud-scaffold/blob/master/spring-cloud-iiford/):

spring.factories(省略無關程式碼)

# AutoConfiguration
org.springframework.boot.autoconfigure.EnableAutoConfiguration=\
    com.github.hashjang.spring.cloud.iiford.service.common.auto.UndertowAutoConfiguration

UndertowAutoConfiguration

//設定proxyBeanMethods=false,因為沒有 @Bean 的方法互相呼叫需要每次返回同一個 Bean,沒必要代理,關閉增加啟動速度
@Configuration(proxyBeanMethods = false)
@Import(WebServerConfiguration.class)
public class UndertowAutoConfiguration {
}

WebServerConfiguration

//設定proxyBeanMethods=false,因為沒有 @Bean 的方法互相呼叫需要每次返回同一個 Bean,沒必要代理,關閉增加啟動速度
@Configuration(proxyBeanMethods = false)
public class WebServerConfiguration {
    @Bean
    public WebServerFactoryCustomizer<ConfigurableUndertowWebServerFactory> undertowWebServerAccessLogTimingEnabler(ServerProperties serverProperties) {
        return new DefaultWebServerFactoryCustomizer(serverProperties);
    }
}

DefaultWebServerFactoryCustomizer

public class DefaultWebServerFactoryCustomizer implements WebServerFactoryCustomizer<ConfigurableUndertowWebServerFactory> {

    private final ServerProperties serverProperties;

    public DefaultWebServerFactoryCustomizer(ServerProperties serverProperties) {
        this.serverProperties = serverProperties;
    }

    @Override
    public void customize(ConfigurableUndertowWebServerFactory factory) {
        String pattern = serverProperties.getUndertow().getAccesslog().getPattern();
        // 如果 accesslog 配置中列印了響應時間,則開啟記錄請求開始時間配置
        if (logRequestProcessingTiming(pattern)) {
            factory.addBuilderCustomizers(builder -> builder.setServerOption(UndertowOptions.RECORD_REQUEST_START_TIME, true));
        }
    }

    private boolean logRequestProcessingTiming(String pattern) {
        if (StringUtils.isBlank(pattern)) {
            return false;
        }
        //判斷 accesslog 是否配置了檢視響應時間
        return pattern.contains(ResponseTimeAttribute.RESPONSE_TIME_MICROS)
                || pattern.contains(ResponseTimeAttribute.RESPONSE_TIME_MILLIS)
                || pattern.contains(ResponseTimeAttribute.RESPONSE_TIME_NANOS)
                || pattern.contains(ResponseTimeAttribute.RESPONSE_TIME_MILLIS_SHORT)
                || pattern.contains(ResponseTimeAttribute.RESPONSE_TIME_SECONDS_SHORT);
    }
}

其他

還有安全相關的屬性(SSL 相關,登入認證 Authentication 相關),微服務內部呼叫一般用不到,我們這裡就不贅述了。
其它內建的屬性,在 Spring Boot 環境下一般用不到,我們這裡就不討論了。

舉例

我們最開始配置的 accesslog 的例子請求返回如下( JSON 格式化之後的結果):

{
	"transportProtocol": "http/1.1",
	"scheme": "http",
	"protocol": "HTTP/1.1",
	"method": "GET",
	"reqHeaderUserAgent": "PostmanRuntime/7.26.10",
	"cookieUserId": "testRequestCookieUserId",
	"queryTest": "1",
	"queryString": "?test=1&query=2",
	"relativePath": "/test, /test, -",
	"requestLine": "GET /test?test=1&query=2 HTTP/1.1",
	"uri": "/test",
	"thread": "XNIO-2 task-1",
	"hostPort": "127.0.0.1:8102",
	"localIp": "127.0.0.1",
	"localPort": "8102",
	"localServerName": "127.0.0.1",
	"remoteIp": "127.0.0.1",
	"remoteHost": "127.0.0.1",
	"bytesSent": "26",
	"time": "2021-04-08 00:07:50.410",
	"status": "200",
	"reason": "OK",
	"respHeaderUserSession": "testResponseHeaderUserSession",
	"respCookieUserId": "testResponseCookieUserId",
	"timeUsed": "3683ms, 3.683s, 3683ms, 3683149 us, 3683149200 ns",
}