Spring Webflux - Netty access log customize

 

 

Web service 에서 사용자 및 외부에서 어떤 요청이 들어왔는지, 혹은 response에 대한 header 에는 어떠한 정보가 담겨져 있는 지 
access log를 통해 확인 및 handling이 가능합니다. 

 

access log를 logging system으로 저장하여, ELK(Elasticsearch, logstash, kibana) 를 활용하거나
EFK (Elasticsearch, Fluentd, Kibana) 를 통해 log monitoring 이 가능합니다. 

 

Spring MVC vs Spring Webflux

Spring MVC 의 경우 embedded tomcat의 access log 를 이용하면 되지만,
Webflux의 경우 default 로 netty 로 돌아가기 때문에 tomcat access log 접근법으로는 access logging을 사용할 수 없습니다. 

더 자세하게 찾아보면, 가능할 수도 있어요...

 

일반적인 netty access logging 처리 

일반적으로 netty access log logging 을 구글링하면, 

먼저 vm options 혹은 jar 실행시, command 로 해당 옵션을 설정하라고 나옵니다. 

-Dreactor.netty.http.server.accessLogEnabled=true

• 주의 : 해당 옵션은 Spring Boot property가 아닌, Java System Property 

 

logback.xml  config 

    <appender name="accessLog" class="ch.qos.logback.core.FileAppender">
        <file>access_log.log</file>
        <encoder>
            <pattern>%m%n</pattern>
        </encoder>
    </appender>
    <appender name="async" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="accessLog" />
    </appender>

    <logger name="reactor.netty.http.server.AccessLog" level="INFO" additivity="false">
        <appender-ref ref="async"/>
    </logger>

• logback, log4j2 에 따라 config 는 달라진다는 점 유의 

이러한 설정들을 마치고 run을 하여 해당 서비스에 request를 날린다면, access log가 남는 것을 확인할 수 있다. 

(nginx 일반적인 access log 와 format 은 동일(?) 비슷(?) 하다고 알고 있다...)

 

123.123.123.123 - - [12/Apr/2018:17:03:50 +0900] "GET /api/aaaa HTTP/1.1" 200 34 1468 

# ref : https://d2.naver.com/helloworld/3585246

 

해당 로그에 담겨지는 element 들은 다음과 같다. 

• host
• user
• aceess DateTime
• method
• uri
• protocol
• status
• content Length
• duration

원한다면 referer, User-Agent 등등 다양한 정보들을 담을 수 있다.

 

 

 

 

 

이제 netty access log 를 customize 해보자

 

구글에 "netty access log customize" 라고 검색하면, 공식 reactor-netty github에서 관련된 Issue 를 찾을 수 있다. 

 

해당 issue에서 pr 로 찾아 들어가게 되면, package reactor.netty.http.server.logging 에 AccessLogHandlerH2 Class 를 통해 customizing 한 결과를 찾을 수 있다.

해당 클래스를 참고해서 customizing을 해도 좋고, 나는 package 내 다른 Class 를 찾다가 `BaseAccessLogHandler` 를 이용하여 Customizing 하기로 했다. 

 

/*
 * Copyright (c) 2020-2021 VMware, Inc. or its affiliates, All Rights Reserved.
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *   https://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */
package reactor.netty.http.server.logging;

import io.netty.channel.ChannelDuplexHandler;
import reactor.util.annotation.Nullable;

import java.net.InetSocketAddress;
import java.net.SocketAddress;
import java.util.function.Function;

import static reactor.netty.http.server.logging.AbstractAccessLogArgProvider.MISSING;

/**
 * @author limaoning
 */
class BaseAccessLogHandler extends ChannelDuplexHandler {

	static final String DEFAULT_LOG_FORMAT =
			"{} - {} [{}] \"{} {} {}\" {} {} {}";

	@SuppressWarnings("deprecation")
	static final Function<AccessLogArgProvider, AccessLog> DEFAULT_ACCESS_LOG =
			args -> AccessLog.create(DEFAULT_LOG_FORMAT, applyAddress(args.remoteAddress()), args.user(),
					args.zonedDateTime(), args.method(), args.uri(), args.protocol(), args.status(),
					args.contentLength() > -1 ? args.contentLength() : MISSING, args.duration());

	final Function<AccessLogArgProvider, AccessLog> accessLog;

	BaseAccessLogHandler(@Nullable Function<AccessLogArgProvider, AccessLog> accessLog) {
		this.accessLog = accessLog == null ? DEFAULT_ACCESS_LOG : accessLog;
	}

	static String applyAddress(@Nullable SocketAddress socketAddress) {
		return socketAddress instanceof InetSocketAddress ? ((InetSocketAddress) socketAddress).getHostString() : MISSING;
	}

}

 

Deprecated 되었다는 어노테이션이 달려있지만, 명시적으로 해당 로그 format에 어떤 element 들어가는 지 확인이 가능하여 해당 클래스 내 로직을 차용하였다. 

 

또한 해당 로직을 작성할 구체 클래스는 WebServerFactoryCustomizer 인터페이스를 implement 해야한다. 

WebServerFactoryCustomizer 의 설명은 링크로 남긴다. 

 

package com.xonmin.playground.webflux.logging;

import java.net.InetSocketAddress;
import java.net.SocketAddress;
import org.springframework.boot.web.embedded.netty.NettyReactiveWebServerFactory;
import org.springframework.boot.web.server.WebServerFactoryCustomizer;
import org.springframework.stereotype.Component;
import reactor.netty.http.server.logging.AccessLog;
import reactor.util.annotation.Nullable;

@Component
public class NettyWebServerCustomizer
	implements WebServerFactoryCustomizer<NettyReactiveWebServerFactory> {

	private static final String LOG_FORMAT =
		"{} - {} [{}] \"{} {} {}\" {} {} {} {} {}";
	
        private static final USER_AGENT = "User-Agent";
    
        private static final REFERER = "Referer";
    
	private static final String MISSING = "-";

	@Override
	public void customize(NettyReactiveWebServerFactory factory) {
		factory.addServerCustomizers(httpServer ->
			httpServer.accessLog(true,
				x -> AccessLog.create(LOG_FORMAT,
					applyAddress(x.remoteAddress()),
					x.user(),
					x.accessDateTime(),
					x.method(),
					x.uri(),
					x.protocol(),
					x.status(),
					x.contentLength() > -1 ? x.contentLength() : MISSING,
					x.duration(),
					x.requestHeader(Referer) != null ? x.requestHeader(Referer) : MISSING))),
                 		        x.requestHeader(USER_AGENT) != null ? x.requestHeader(USER_AGENT) : MISSING)));
	}

	private static String applyAddress(@Nullable SocketAddress socketAddress) {
		return socketAddress instanceof InetSocketAddress ? ((InetSocketAddress) socketAddress).getHostString() :
			MISSING;
	}
}

 

이처럼 설정한다면, 이와 같은 형식으로 로그에 추가적인 정보들이 담겨, logging 처리가 가능하다. 

 

123.123.123.123 - - [12/Apr/2018:17:03:50 +0900] "GET /api/aaaa HTTP/1.1" 200 34 1468 "https://m.naver.com" "Mozilla/5.0 (iPhone; CPU iPhone OS 11_3 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E216 NAVER(inapp; search; 580; 8.6.3; 7)"