如何配置accesslog以及accesslog 的各种占位符

这期内容当中小编将会给大家带来有关如何配置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。

请求相关属性

注意：

1. 路径参数 PathVariable 由于并没有被 Undertow 的 Listener 或者 Handler 解析处理，所以拦截不到，无法确认是否是一个 PathVariable 还是就是 url 路径。所以，PathVariable 的占位符是不会起作用的。

请求地址相关

注意：

1. 请求的远程地址我们一般不从请求连接获取，而是通过 Http Header 里面的 X-forwarded-for 或者 X-real-ip 等获取，因为现在请求都是通过各种 VPN，器发上来的。

响应相关属性

注意：默认 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",
}