이상을 꿈꾸는 몽상가.. 프로그래밍을 좋아함..


Log4j 2 설정하기

Apache Logging Service Logo
(이미지 출처 : https://logging.apache.org)

Configuration 파일을 어디다가 둬야 혹은 어떻게 처리해야 Log4j 를 사용할 수 있을까요?
저는 예전에는 이것 때문에 굉장히 애를 먹었습니다.

분명 Spring을 쓸 때는 src/main/resources 아래에 두면 잘 돌아갔었습니다.
근데 프레임워크가 없는 레거시 시스템에 적용하려고보니 당연히도 src/main/resources가 없죠.
알고보니 WAS의 web.xml 에서 설정해야 하더군요.
또 다른 프로젝트로 가서 적용하려다보니 Daemon으로 돌리는 시스템이라 WAS가 없고 web.xml이 없더군요.

Log4j 를 접하면 저는 항상 당황스러움이 가장 먼저 떠오릅니다.

그래서 가장 우선적으로 configuration을 적용하는 방법을 설명합니다.
그리고 Log4j 2 에서 제공하는 강력한 성능의 비동기방식 로깅처리에 대해서 알아보겠습니다.
Configuration 작성법은 샘플을 통해서 간략히 설명하겠습니다.

Configuration 적용 방법

Log4j will inspect the “log4j.configurationFile” system property and, if set, will attempt to load the configuration using the ConfigurationFactory that matches the file extension.
If no system property is set the properties ConfigurationFactory will look for log4j2-test.properties in the classpath.
If no such file is found the YAML ConfigurationFactory will look for log4j2-test.yaml or log4j2-test.yml in the classpath.
If no such file is found the JSON ConfigurationFactory will look for log4j2-test.json or log4j2-test.jsn in the classpath.
If no such file is found the XML ConfigurationFactory will look for log4j2-test.xml in the classpath. If a test file cannot be located the properties ConfigurationFactory will look for log4j2.properties on the classpath.
If a properties file cannot be located the YAML ConfigurationFactory will look for log4j2.yaml or log4j2.yml on the classpath.
If a YAML file cannot be located the JSON ConfigurationFactory will look for log4j2.json or log4j2.jsn on the classpath.
If a JSON file cannot be located the XML ConfigurationFactory will try to locate log4j2.xml on the classpath.
If no configuration file could be located the DefaultConfiguration will be used. This will cause logging output to go to the console.
( 출처 : Log4j 2 Manual)

“log4j.configurationFile” 라는 system property 에 입력하거나 configuration 파일을 class path 에 위치시키면 된답니다.
좀 더 구체적인 상황을 아래에 적어봤습니다.

  • Configuration 위치를 Java 실행변수에 입력
    • Dlog4j.configurationFile 실행변수 에
      $ java -Dlog4j.configurationFile=path/confFileName.xml ......
    
  • Configuration 위치를 소스상에서 입력

      System.setProperty(XmlConfigurationFactory.CONFIGURATION_FILE_PROPERTY,"path/confFileName.xml");
    
      OR
    
      System.setProperty(PropertiesConfigFactory.CONFIGURATION_FILE_PROPERTY,"path/confFileName.properties");
    
  • Configuration을 class path 에 위치시키기
    • java 파일들을 빌드해서 생성된 class 파일들이 위치하는 class path 에 위치시키면 됩니다.
    • 기본 파일명규칙을 지켜야합니다.
      log4j2.xml, log4j2.properties, log4j2.json, log4j2.jsn, log4j2.yaml, log4j2.yml

Maven, Gradle 을 사용하는 시스템

src/main/resources 에 위치한 파일들이 빌드시에 Maven에 의해서 class path로 이동됩니다.
Configuration 파일들을 src/main/resources 에 위치시켜서 적용시키는 것이 일반적인 방법입니다.
테스트 코드에 대해서는 src/test/resources 에 위치시키면 되겠죠.
Spring 프레임워크를 사용하시는 프로젝트라면 아마도 Maven 또는 Gradle 을 사용할 것입니다.

WAS 를 사용하는 시스템

web.xml 파일을 이용해서 아래와 같은 Java 실행변수 값을 입력하는 것이 일반적인 방법입니다.

  log4j.configurationFile=path/confFileName.xml

Daemon 으로 돌아가는 시스템

일반적인 방법에 대해서까지는 모르겠습니다.
ANT, Gradle, Shell 등을 잘 작성해서 class path 에 계속해서 위치시키는 방법도 있겠지만 귀찮아 보입니다.
Java 실행변수에 configuration 위치를 직접 입력하거나 Daemon 의 main문이 실행시 소스상에서 위치를 입력합니다.

Asynchronous Logging

Async Logging Throughput

(이미지 출처 : https://logging.apache.org )

위 이미지를 보면 Sync 방식에 비해 Loggers Async 방식의 시간당 처리량(msg/sec)이 좋은 것을 볼 수 있습니다.
그리고 멀티쓰레드 환경에서 그 성능차이가 훨씬 크다는 것이 확인됩니다.

Async Appender 라는 것도 있지만 무시해도 될 것 같습니다.
sync 방식에 비해 빠르기 때문에 기존에는 좋은 방식이었을지 모르지만 Loggers Async 방식이 나오면서 포지션이 어중간해졌습니다.

Async Logging Throughput

( 이미지 출처 : https://logging.apache.org )

위 이미지를 보면 Log4j 1 이나 Logback 보단 Log4j 2의 Loggers Async 를 이용해야겠다는 생각이 들게됩니다.

주의사항

비동기 방식이다보니 logging 요청시기와 실제 logging 기록시기가 다릅니다.
요청시기와 기록시기 사이에 데이터가 변경되는 경우 요청했던 당시의 상황이 왜곡되어 기록될 수 있습니다.

하지만 변경되지 않을 데이터를 기록하도록 요청함으로써 해결가능합니다.
가장 좋은 방법은 String 같은 immutable object 혹은 int, long 같은 variable 위주로 로깅을 하는 것입니다.

    Logger logger = Logger.getLogger("Application");

    String msg = "원본 메시지";
    logger.info(msg); // String 은 immutable object

    MessageObject msgObject = new MessageObject(); // 임의의 object
    msgObject.setMsg(msg);
    logger.info(msgObject); /* "변경될지도 모른다." 라고 출력 될 수도 있습니다.
        muttable object는 변경될 가능성이 있습니다.

        이미 수많은 로깅 요청이 들어와있거나 
        동시에 여러 쓰레드에서 로깅 요청 중이거나
        파일 I/O에 과정에서 알수없는 delay가 생긴다는 등등의 상황에 의해서 
        로그기록 시점이 늦어진다면 아래 라인이 먼저 수행될 수도 있습니다.    
    */
    msgObject.setMsg("변경될지도 모른다.");

    msgObject.setMsg("변경될리 없다.");
    logger.info(msgObject.toString()); /* "변경될리 없다." 라고 출력됩니다. 
        String 으로 넘겨졌기 때문에 변경될리 없습니다. 
    */
    msgObject.setMsg("버려지는 메시지");

    logger.info(12345);

인터넷을 돌아다니다보니 로깅과정에서 데이터가 변경되는 상황을 보여주고자 이상한 코드를 구현한 경우를 봤습니다.
여러 쓰레드에서 static 변수를 변경하고 해아 변수를 로깅해서 억지로 상황을 발생시키고 있었습니다.
내가 보기엔 적절한 예는 아니라고 봅니다.

위의 MessageObject 를 static으로 선언하고 여러 쓰레드에서 값을 바꾼다고 생각해봅시다.
logger.debug(msgObject) 를 통해 logger에게 msgObject가 넘어간 후에 msgObject가 변경될 수 있습니다.
하지만 msgObject.toString() 을 하는 과정에서도 그 값은 바뀔 수 있습니다.

    static MsgObject msgObject = new MessageObejct(); // 임의의 object

    ..(생략)

    Logger logger = Logger.getLogger("Application");

    msgObject.setMsg("현재 쓰레드의 메시지");

    /* 
        만약 이 타이밍에 다른 쓰레드에서 static msgObject를 변경한다면?
        예를들어 msgObject.setMsg("다른 쓰레드의 메시지"); 라고 입력된다면?
    */
    String msg = msgObject.toString();

    logger.info(msg); // "다른 쓰레드 메시지" 라고 출력 될 것입니다.

이것은 log4j가 비동기방식이기 때문에 발생한 것이 아닙니다.
만약 “다른 쓰레드의 메시지” 라고 출력되는 것이 문제가 된다면 log4j를 동기방식으로 바꾼다고 해결되는 문제가 아닙니다.
단순히 멀티 쓰레드 환경에서 잘못된 코딩을 했기 때문에 발생하는 상황입니다.

Configuration 샘플

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN" name="MyApp">
  <Appenders>
    <RollingRandomAccessFile name="LogApp" fileName="log/app.log" filePattern="log/app/app-%d{yyyy-MM-dd_HH}_%i.log" immediateFlush="false" append="true" ignoreExceptions="false">
        <PatternLayout>
            <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
        </PatternLayout>

        <Policies>
            <TimeBasedTriggeringPolicy interval="6" modulate="true"/>
            <SizeBasedTriggeringPolicy size="4 MB"/>
        </Policies>
        <DefaultRolloverStrategy max="500"/>
    </RollingRandomAccessFile>

    <RollingRandomAccessFile name="Exception" fileName="log/excetpion.log" filePattern="log/exception/exception-%d{yyyy-MM-dd_HH}_%i.log" immediateFlush="false" append="true" ignoreExceptions="false">
        <PatternLayout>
            <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
        </PatternLayout>

        <Policies>
            <TimeBasedTriggeringPolicy interval="6" modulate="true"/>
            <SizeBasedTriggeringPolicy size="4 MB"/>
        </Policies>
        <DefaultRolloverStrategy max="500"/>
    </RollingRandomAccessFile>

    <Async name="ASYNC_LogApp" includeLocation="true">
        <AppenderRef ref="LogApp" />
    </Async>

    <Async name="ASYNC_Exception" includeLocation="true">
        <AppenderRef ref="Exception" />
    </Async>

  </Appenders>

  <Loggers>
    <Logger name="Application" level="info" additivity="false">
        <AppenderRef ref="ASYNC_LogApp"/>
    </Logger>
    <Root level="error">
      <AppenderRef ref="ASYNC_Exception"/>
    </Root>
  </Loggers>
</Configuration>

Loggers 에 RottLogger를 포함해서 여러개의 Logger 를 설정할 수 있습니다.
Java 소스에서는 Logger 의 name 을 이용해서 어떤 Logger 를 사용할지 선택하게 됩니다.

위의 sample 의 Application 이라는 Logger를 사용하기 위해서는
Java 소스상에서 아래와 같이 Logger instance를 호출시에 Logger 의 name 을 입력하면 됩니다.

Logger logger = Logger.getLogger("Application");

보통은 전체 package 를 Root Logger 에 연결해서 사용하거나
Logger name 으로 해당 Logger 를 사용하고자하는 package 의 이름을 넣습니다.
그러면 그 package 의 모든 하위 package 에서 해당 Logger 를 사용할 방법이 생깁니다.
아래에서 사용방법을 알아보겠습니다.

< package 구성 >

    - io.dveamer.project
        - package1
            - sub11
            - sub12
        - package2
            - sub21
            - sub22
<!-- XMl 의 일부 -->

  <Loggers>
    <Logger name="io.dveamer.project.package1" level="info" aditivity="false">
        ..(생략)
    </Logger>
    <Logger name="io.dveamer.project.package2" level="info" aditivity="false">
        ..(생략)
    </Logger>
  </Loggers>
/* Java class 의 일부 */

    package io.dveamer.project.package1.sub11

    ..(생략)

    Logger logger = Logger.getLogger(this.getClass());

위와 같이 Java 소스에서 this.getClass() 를 파라미터로 넘기면
해당 class 의 package 정보를 이용해서 해당 package 가 소속된 Logger 를 제공해줍니다.

위와 같이 io.dveamer.project.package1.sub11 아래에 위치한 class 는 XML 의 첫번째 Logger 를 사용하게 됩니다.

중복로그 제거하기 (Additivity)

Root Logger는 시스템에서 발생되는 Log4j 관련 모든 로그를 기록하는 것이 기본 모드입니다.
만약 다음과 같이 설정하게 되면 Log/App/app.log 파일에 남는 로그들이 Log/Exception/excetpion.log 에도 중복되어 남게됩니다.

<Logger name="Application" level="info" >

additivity="false" 를 추가함으로써 위와 같은 상황을 막을 수 있습니다.

<Logger name="Application" level="info" aditivity="false">

이로써 Log/Exception/excetpion.log 파일에는 시스테 전체의 error 로깅만 기록 되고
Log/App/app.log 파일에는 Application 으로 호출된 Logger의 info 로깅만 기록됩니다.

References


Donations ❤

제가 작성한 글이 작게라도 도움이 되었기를 바랍니다.
관심 가져주시는 분이 있는 것을 느끼고 힘내기 위해 기부 버튼을 만들어봤습니다.
혹시 가능하시다면 $1 라도 기부 부탁드립니다 ^^





Associated Posts

관련된 주제를 살펴볼 수 있도록 동일한 Tag를 가진 글들을 모아뒀습니다. 제목을 눌러주세요.


Disqus Social Community

SNS계정으로 댓글을 달아도 SNS에 글이 남지 않습니다.
이메일 주소 입력으로 글을 남길 수 있으며, 답변이 달리면 이메일로 알림을 받을 수 있습니다.

i