VisualVM을 이용한 log4j2 로그 수준 변경 및 모니터링

2021. 3. 29. 13:07 Java 관련/log4j, slf4j

| VisualVM

VisualVM은 JVM 에서 동작하는 어플리케이션의 프로파일링 및 모니터링을 제공하는 GUI 툴입니다. 현재 다니고 있는 회사에서는 다른 JVM 모니터링 툴을 사용하지 않고 VisualVM을 통해 모니터링 및 프로파일링을 하고 있습니다.

다른 상용 툴(ex. 제니퍼소프트 제품들)들을 써보지 않아서 모르겠지만 VisualVM 만으로 아직까지는 큰 불편없이 19만줄 가량되는 마이크로아키텍처 기반 데이터 파이프라이닝 프로젝트를 운영하고 있습니다.

| 실행 환경

Window 10 home
Java 1.8
IntelliJ IDE( Not Required )

| VisualVM을 이용한 log4j2 로그 수준 변경

운영을 하는 도중에 특정 Logger의 로깅 레벨 수준을 높여 DEBUG 및 TRACE 성 로그를 추적하고 싶을 때가 있습니다. 이 때 VisualVM을 이용하여 로컬 개발 PC에서 원격으로 운영 서버에 접속하여 어플리케이션 로깅 시스템의 로깅 레벨 수준을 높일 수 있습니다.

그 중에서 log4j2 기반인 로깅 시스템에서 VisualVM을 통해 어떻게 로그 수준을 변경하고 어플리케이션이 어떻게 동작하는 지 알아 보겠습니다.

프로젝트 구조

+---src
|   +---main
|   |   +---java
|   |   |   \---com
|   |   |       |   Com.java
|   |   |       |
|   |   |       \---dev
|   |   |               ComDev.java
|   |   |
|   |   \---resources
|   |           log4j2.xml

의존성 설정

<dependencies>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-slf4j-impl</artifactId>
        <version>2.11.2</version>
    </dependency>
</dependencies>

slf4j의 log4j2의 구현체를 쓰게되면 바로 log4j2 기반인 로깅시스템을 쓸 수 있습니다.

log4j2.xml 설정 파일

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
    <Appenders>
        <Console name="console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy-MM-dd'T'HH:mm:ss.SSS} [%t] %p %m%n"/>
        </Console>
    </Appenders>
    <Loggers>
        <Root level="WARN" additivity="false">
            <appender-ref ref="console"/>
        </Root>
        <Logger name="com" level="WARN" additivity="false">
            <appender-ref ref="console"/>
        </Logger>
        <Logger name="com.dev" level="TRACE">
            <appender-ref ref="console"/>
        </Logger>
    </Loggers>

</Configuration>

log4j2.xml 파일에서 로거들은 루트 로거와 com 및 com.dev 패키지 경로를 기반으로 하는 com.dev 로거 정보들을 설정해 놓았습니다. com은 WARN, com.dev 는 TRACE 레벨입니다.

소스 코드

package com;

import com.dev.ComDev;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Com {

    private static Logger logger = LoggerFactory.getLogger(Com.class);

    public static void main(String[] args) {
        while(true) {
            logger.warn("This is [com] main warning ");
            new ComDev();
            Thread.sleep(3000);
        }
    }

}

package com.dev;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class ComDev {

    private static Logger logger = LoggerFactory.getLogger(ComDev.class);

    public ComDev() {
        logger.trace("This is [com.dev] trace warning ");
    }

}

단순 로그 메세지를 띄우는 코드입니다. 두 코드모두 자신의 로그 레벨에 맞는 로그 메시지를 출력하기 때문에 아래와 같이 콘솔에 출력화면이 뜰 수 있습니다. ( Com 클래스는 WARN, ComDev 클래스는 TRACE )
main 진입점에서 while 문으로 계속해서 로그 메세지를 출력하는 코드를 작성하였습니다.

실행 설정

IntelliJ 기준으로 Run Configuration에서 VM Option을 다음과 같이 줍니다.

-Dcom.sun.management.jmxremote.port=3000 -Dcom.sun.management.jmxremote.authenticate=false

만일 IntelliJ 가 아닌 다른 IDE거나 명령어창으로 실행할 경우 아래와 같이 VM Option을 준 후 실행합니다.

java.exe -Dcom.sun.management.jmxremote.port=3000 -Dcom.sun.management.jmxremote.authenticate=false

위에서 -Dcom.sun.management.jmxremote.port 는 jmx 포트를 설정하는 옵션이고 -Dcom.sun.management.jmxremote.authenticate 옵션은 jmx 접속시 권한이 있는 지를 체크하는 옵션입니다. 지금은 단순 테스트라서 옵션을 꺼놓았습니다.

결과 화면

2019-05-30T23:26:17.031 [main] WARN This is [com] main warning
2019-05-30T23:26:17.047 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:26:17.047 [main] TRACE This is [com.dev] trace warning 
...

VisualVM

VisualVM은 보통 JDK를 설치할 때 번들로 제공되며 JDK가 인스톨된 디렉터리의 bin 디렉터리에 있습니다.
VisualVM을 키면 왼쪽의 Application 탭에 위에서 실행했던 어플리케이션이 Application 탭에 나타난 것을 볼 수 있습니다.
처음 VisualVM을 실행하게 되면 MBeans를 VisualVM에서 제어할 Plugin이 설치가 안 된 상태입니다. Tools -> Plugins 에서 VisualVM-MBeans Plugin을 설치합니다.
MBean은 Managed Bean이라하며 표준 스펙에 맞춰 개발된 관리 인터페이스라고 생각하시면 됩니다. 이 인터페이스를 통해 JMX 상에서 어플리케이션을 제어할 수 있게 됩니다.

Plugin을 설치하면 아래와 같이 VisualVM에서 MBean을 통해 어플리케이션을 제어하게 됩니다. log4j2는 MBean 스펙을 준수하여 작성되었기 때문에 VisualVM 상에서 log4j2 로깅 시스템의 속성들을 제어할 수 있습니다.

아래와 같이 com 로거의 로그 수준을 ERROR로 낮추게 되면 WARN 메세지를 출력하는 com 로거는 로그 수준이 높기 때문에 메세지가 출력되지 않게 됩니다.

2019-05-30T23:55:21.149 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:21.149 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:24.149 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:24.149 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:27.150 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:27.150 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:30.150 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:30.150 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:33.155 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:33.155 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:36.155 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:36.155 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:39.156 [main] TRACE This is [com.dev] trace warning
2019-05-30T23:55:39.156 [main] TRACE This is [com.dev] trace warning