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

上一节我们讲述了如何使用 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 中即可。请看下面的代码(项目地址://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",
}