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

Posted 2021-09-14 张哈希

上一节我们讲述了如何使用 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值}	分别对应 CookieAttribute 和 RequestCookieAttribute
路径参数 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}	无	分别对应 RelativePathAttribute 和 RequestPathAttribute 和 ResolvedPathAttribute
请求整体字符串，包括请求方法，请求相对路径，请求参数字符串，请求协议，例如 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",
}