Logback SDK 사용 방법

이 장에서는 Effective Log Search & Analytics Logback SDK를 사용하는 방법을 설명하기 위하여 작성되었습니다. NELO는 Effective Log Search & Analytics의 프로젝트 코드 네임입니다.

NELO2 Logback SDK dependency 추가

압축파일 해제 후 나오는 core 모듈과 logback 모듈 두 개의 파일을 의존성에 추가합니다.

비고

  • 이 SDK는 logback의 slf4J 바인딩 라이브러리인 logback-classic을 포함하여 제공하고 있습니다. slf4j는 특성상 동시에 하나의 binding만 지원하므로, 다른 slf4j 바인딩을 위한 라이브러리를 같이 사용하면 안됩니다.

  • Logback 라이브러리 중 SLF4J binding 라이브러리는 logback-classic입니다. 기존에 사용하던 참조 라이브러리와 nelo2 logback SDK에서 참조하는 라이브러리가 중복될 경우 문제가 발생할 수 있습니다. 이때는 보다 상위의 버전을 사용하는 것을 권장합니다.

Effective Log Search & Analytics logback appender 설정 및 옵션

Logback은 logback.groovy -> logback-test.xml -> logback.xml 순서로 설정 파일을 찾습니다.

이 문서에서는 logback.xml을 기준으로 설명합니다. 보통 사용하는 logback.xml 설정은 다음과 같습니다.

<configuration>
    <!-- Console Appender -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss} [%-5level]\(%file:%line\) %msg%n</pattern>
        </encoder>
    </appender>
    <!-- Logger -->
    <logger name="com" additivity="false">
        <level value="debug"/>
        <appender-ref ref="STDOUT" />
    </logger>
    <!-- Root Logger -->
    <root level="warn">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

NELO2 Logback appender는 아래와 같이 설정할 수 있습니다.

<appender name="nelo" class="com.naver.nelo2.logback.ThriftAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>TRACE</level>
    </filter>
    <param name="projectName" value="프로젝트 아이디"></param>
    <param name="collectorUrl" value="elsa-col.ncloud.com"></param>
    <param name="encoding" value="utf-8"></param>
    <param name="timeout" value="1200"></param>
    <param name="enable" value="true"></param>
    <param name="debug" value="false"></param>
    <param name="version" value="1.0.0"></param>
    <param name="errorCodeType" value="default"></param>
    <param name="port" value="10006"></param>
    <param name="isBulkEnabled" value="true"></param>
</appender>

옵션은 다음과 같은 항목들을 설정할 수 있습니다.

  • Appender (전송 프로토콜에 따라 Appender의 클래스명을 선택)

    • Thrift Appender : com.naver.nelo2.logback.ThriftAppender

    • Http Appender : com.naver.nelo2.logback.HttpAppender

  • projectName: 프로젝트 아이디. Effective Log Search & Analytics의 프로젝트 정보에서 생성한 프로젝트의 아이디를 확인할 수 있습니다.

  • version : 프로젝트 버전(영문, 숫자, -, , .만 허용되고 영문/숫자/로 시작하여야 합니다).

  • collectorUrl: Effective Log Search & Analytics 로그 수집 서버의 URL

  • port: Collector 서버 port

    • Thrift Appender : 10006

    • Http Appender : 80

  • enable: 사용 여부(기본값 true)

  • logType : logType 설정

  • logSource : logSource 설정

  • errorCodeType: 에러코드 타입

    • default: Logback 기본 정보 중 Exception 정보를 사용함. Exception 정보가 전달되지 않은 경우 (log.error(message)의 형식으로 로그가 기록되는 경우)에는 에러 메시지 전체를 에러코드로 사용함
      예시) NullPointerException이 발생한 경우 => NullPointerException

    • message: 에러 메시지의 처음부터 공백문자까지만 사용함.
      예시) 다운로드에러 다운로드가 실패했습니다. => 다운로드에러

    • mdc: SLF4J MDC의 ‘errorCode’ 항목값을 설정해서 사용한다.
      예시)MDC.put(“errorCode”, “Login”) => Login

  • debug: Nelo2 appender의 디버깅용 메시지 출력, 기본값 false

    • 이 옵션값은 전역적으로 적용되고, 'true'가 'false'에 우선합니다. 즉, 여러 어펜더가 선언되어있고, 그 중 하나의 debug 값이 true일 경우, 모든 어펜더에서 콘솔에 디버그 로그를 출력하게 됩니다.
  • timeout: 전송 시 사용되는 socket의 타임아웃, 기본값 5000ms(5초)

  • keepAlive: 전송 시 사용되는 socket의 keepAlive 타임아웃, 기본값 60000ms(1분), 최대값 180000ms(3분)

  • isBulkEnabled : bulk모드를 사용할지 여부, 기본값 true, false일 경우 매건 로그를 개별적으로 전송

  • bulkSize : bulk모드를 사용할 경우 한 벌크에 전송될 최대 로그의 수, 기본값 1000, 최대값 100000

  • bulkInterval : bulk모드를 사용할 경우 벌크 요청을 호출하는 주기, 기본값 1000ms(1초), 최대값 10000ms(10초)

bulk/single

Effective Log Search & Analytics logback SDK는 로그전송을 건당으로 보내는 single 모드와 묶음단위로 전송하는 bulk 모드를 지원합니다.

xml appender 설정에서 isBulkEnabled를 true/false로 하여 bulk / single 모드를 사용할 수 있습니다(기본값 true).

성능에 관한 레퍼런스는 프로토콜에 따라 아래의 표를 참조하여 주십시오.

10분간 단일 스레드에서 1kb size의 로그를 전송할 시의 throughput
  • thrift
    • single mode : 2587.93 logs/sec
    • bulk mode : 6492.99 logs/sec
  • http
    • single mode : 595.86 logs/sec
    • bulk mode : 4617.98 logs/sec

위 성능 테스트에 사용한 장비의 사양은 다음과 같습니다.

  • 로그 전송 서버 : 2GHZ 12core cpu, 48G mem
  • 로그 수집 서버 : 2.26GHZ 12core cpu, 48G mem

비고

  • 부하에 따라 전송 성능은 다를 수 있습니다. 테스트는 부하가 없는 상황에서 구동하였으며, 실제 사용 중인 인스턴스로 전송 시에는 비교적 낮은 성능을 보입니다. 인스턴스 부하에 따른 성능 체감은 bulk에 비해 single 모드에서 더 크게 나타납니다. 따라서 기본값인 bulk 모드를 사용하시기를 권장합니다.

  • 수집 서버가 허용하는 최대 패킷의 사이즈는 30MB입니다. 클라이언트 서버의 로그 패턴을 고려하여 적절한 bulkSize를 설정해야 합니다(기본값 1000)

AsyncAppender

아래처럼 logback에서 지원되는 AsyncAppender를 이용하여 같은 방식의 결과를 얻으실 수 있습니다.

주의하셔야 할 설정값들은 다음과 같은 것들이 있습니다. queueSize 기본값이 128이나 몇몇 애플리케이션에서는 충분하지 않을 수 있습니다.

그리고 includeCallerData 기본값이 false로 이 경우 AsyncAppender는 로그의 발생 위치 정보를 무시하게됩니다.

아래의 AsyncAppender 설정 예시를 참조하여 주십시오.

<appender name="nelo-logback-async" class="ch.qos.logback.classic.AsyncAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>ERROR</level>
    </filter>
    <param name="neverBlock" value="true" />
    <param name="includeCallerData" value="true" />
    <param name="queueSize" value="2048" />
    <appender-ref ref="nelo-logback" />
</appender>

설정값들의 상세정보에 관해서는 다음의 공식 문서를 참조하십시오.

AsyncAppender 사용 방법

기본적으로 사용하는 ThriftAppender에 추가적으로 LogbackAsyncAppender를 사용하여 실제 로그 전송작업을 별도의 스레드에서 수행하도록 설정할 수 있습니다.

이를 위해서는 아래와 같이 xml 파일을 설정하여 사용하면 됩니다.

<configuration>
    <!-- Console Appender -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss} [%-5level]\(%file:%line\) %msg%n</pattern>
        </encoder>
    </appender>

    <!-- NELO2 Logback Appender -->
    <appender name="nelo-logback" class="com.naver.nelo2.logback.ThriftAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
        <param name="projectName" value="프로젝트 아이디"/>
        <param name="collectorUrl" value="elsa-col.ncloud.com"/>
        <param name="port" value="10006"/>
        <param name="timeout" value="1200" />
        <param name="enable" value="true" />
        <param name="errorCodeType" value="default" />
    </appender>

    <!-- NELO2 Logback Async Appender -->
    <appender name="nelo-logback-async" class="com.naver.nelo2.logback.LogbackAsyncAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
        <param name="BlockWhenFull" value="false" />
        <param name="IncludeCallerData" value="true" />
        <param name="QueueCapacity" value="2048" />
        <appender-ref ref="nelo-logback" />
    </appender>

    <!-- Logger -->
    <logger name="com" additivity="false">
        <level value="debug"/>
        <appender-ref ref="STDOUT" />
        <appender-ref ref="nelo-logback-async" />
    </logger>

    <!-- Root Logger -->
    <root level="warn">
        <appender-ref ref="STDOUT" />
        <appender-ref ref="nelo-logback-async" />
    </root>
</configuration>

Effective Log Search & Analytics logback SDK 사용 예

Effective Log Search & Analytics Logback SDK를 사용하는 실제 코드 예입니다.

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

private static Logger logger = LoggerFactory.getLogger(LogbackTest.class);
...
    logger.debug("Effective Log Search & Analytics Logback SDK Debug Message");
    try {
        String npe = null;
        npe.toString();
    } catch(Exception e) {
        logger.error("Effective Log Search & Analytics Logback SDK Exception", e);
    }

제약 사항

  • async appender를 사용하는 경우, 전송 속도에 비해 로그 발생 속도가 빠르면 queue size를 초과하여 발생한 로그는 전송되지 않습니다.
  • async appender와 기본 appender는 아래의 기준에 따라 선택하는 것을 권장합니다.
    • 로그 유실을 최소화하고 싶은 경우: 기본 appender
    • Effective Log Search & Analytics 시스템 장애 시 애플리케이션 성능 저하가 우려되는 경우: asnyc appender

트러블 슈팅

1. Effective Log Search & Analytics로 로그를 전송했지만, 이를 웹에서 확인할 수 없는 경우

프로젝트 아이디가 올바른지를 확인합니다. 프로젝트 아이디가 올바르지 않은 경우, 웹 대시보드에서 로그를 확인할 수 없습니다.

그리고 실제 오류 데이터가 전송되는지 확인합니다. 설정 파일(logback.xml)에서 nelo2 appender의 debug 속성을 true로 설정한 후 실행해서 아래와 같은 전송 로그가 출력되는지 확인합니다.

<!-- NELO2 Logback Appender -->
<appender name="nelo-logback" class="com.naver.nelo2.logback.ThriftAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>ERROR</level>
    </filter>
    <param name="projectName" value="%YOUR_PROJECT_ID%"/>
    <param name="collectorUrl" value="elsa-col.ncloud.com"/>
    <param name="port" value="10006"/>
    <param name="timeout" value="1200" />
    <param name="enable" value="true" />
    <param name="errorCodeType" value="default" />
    <param name="debug" value="true" />
</appender>

[NELO2] Log Append : sent event, return value :
…

FAQ

1. 배치 프로그램(혹은 간단한 테스트 프로그램)에서 AsyncAppender를 사용하려면?

batch 프로그램의 마지막에 몇초간 대기하는 코드를 추가하여야 합니다.

try {
    Thread.sleep(3000L);
} catch (InterruptedException ignore){}

AsyncAppender는 내부에 로그를 기록하는 별도의 데몬 스레드가 있어서 비동기로 로그를 전달합니다.

Java batch program에서는 main thread가 바로 종료되기 때문에 log4jAsyncAppender의 데몬 스레드가 생성되어 로그를 보내기 전에 batch 애플리케이션이 종료됩니다.

데몬 스레드와 상관없이 살아 있는 일반 스레드가 없을 경우에 JVM은 바로 종료됩니다.

따라서, 위와 같이 프로그램 마지막에 대기하는 코드를 추가하여 모든 로그를 보내고 나서 종료하도록 합니다.

2. Java stack trace를 logback에 로깅하려면?

Action / BO / DAO / Java batch program 등에서 logback을 이용하여 stack trace를 출력하려면 log.error(e.getMessage(), e); 형태를 사용하면 됩니다.

SLF4J Logger는 메서드의 인자로 Throwable만 받는 로깅 메서드는 지원하지 않습니다.

String[] aa = null;
try {
    aa[0] = "111";
} catch (NullPointerException e) {
//    log.error(e); //SLF4J에서는 지원하지 않는 메서드.
    log.error(e.getMessage(), e); ///stacktrace 출력
}

3. logback logging으로 인한 성능 저하를 최소화하려면?

logback.xml의 logger 설정에서 name과 level을 사용하여 filtering을 최대화할 수 있습니다.

아래처럼 logger 설정에서 com이나 org를 DEBUG level로 설정하게 되면 logger에서 많은 ILoggingEvent(logback)가 불필요하게 생성됩니다.

nelo logback appender에서 Threshold가 ERROR로 설정되어 있어 실제 로그 전송은 되지 않지만 일단 logger에서 ILoggingEvent가 생성이 되어 appender에 전달이 됩니다.

성능이 저하되는 설정(개발용으로만 사용)

<!-- Logger -->
<logger name="com" additivity="false">
    <level value="debug"/>
    <appender-ref ref="STDOUT" />
    <appender-ref ref="nelo-logback" />
</logger>

<!-- Logger -->
<logger name="org" additivity="false">
    <level value="debug"/>
    <appender-ref ref="STDOUT" />
    <appender-ref ref="nelo-logback" />
</logger>

<!-- Root Logger -->
<root level="warn">
    <appender-ref ref="STDOUT" />
    <appender-ref ref="nelo-logback" />
</root>

성능이 고려된 설정(운영용으로 사용)

<!-- Logger -->
<logger name="com" additivity="false">
    <level value="error"/>
    <appender-ref ref="STDOUT" />
    <appender-ref ref="nelo-logback" />
</logger>

<!-- Root Logger -->
<root level="warn">
    <appender-ref ref="STDOUT" />
    <appender-ref ref="nelo-logback" />
</root>

4. WAS에서 사용 시 안정적으로 종료하려면?

에러로그가 전송중인 상황에서 WAS(Tomcat 등)가 종료되는 경우에는, 다음과 같은 Exception이 발생하며 WAS가 정상적으로 종료되지 않을 수 있습니다.

이러한 현상을 방지하기 위해서는 WAS 종료시에 LoggerContext 인스턴스에 대해 stop() 메서드를 호출하여 nelo2 java appender를 close하면 안정적으로 종료가 가능합니다.

비고

Spring에서는 Log4J에 대해서는 org.springframework.web.util.Log4jConfigListener를 제공하지만, Logback에 대해서는 안정적인 종료를 지원하는 Listener를 제공하지 않고 있습니다.

Nelo2 logback SDK에서는 자체적으로 LogbackShutdownListener를 제공합니다. web.xml에 다음과 같은 설정을 추가하면 WAS 종료시에 에러로그 전송이 일어나도 안정적인 종료가 가능합니다.

<listener>
    <listener-class>
        com.naver.nelo2.logback.LogbackShutdownListener
    </listener-class>
</listener>

5. thrift bulk 전송 시 timeout이 발생할 경우

수집 서버에 정상적으로 로그를 전송하지 못한 경우 아래와 같은 로그를 확인할 수 있습니다.

[NELO2] sendMessage (1426319665440) sendBulk failed..  Error occur : java.net.SocketTimeoutException: Read timed out

이 경우 xml appender 설정에서 timeout을 증가시키고, bulkSize를 낮추어 한 패킷에 들어갈 데이터를 줄여야 합니다.

6. 메모리 사용량 관련 주의 사항

현재 제공되는 SDK는 bulk 전송 모드를 기본으로 사용하고, bulkSize는 기본값이 1000입니다.

하나의 Effective Log Search & Analytics 로그는 projectName 등 여러 필드를 포함하고 있기 때문에, 로그 바디가 매우 짧은 경우에도 1KB 정도의 메모리를 차지합니다.

따라서 기본 설정인 경우, 벌크는 (로그 사이즈+1KB)*1000 만큼의 메모리를 차지합니다.

자바 프로세스를 기동할 때, 최대 힙을 -Xmx 옵션으로 지정할 수 있습니다. 이 때 위에서 언급한 부가적인 메모리 사용량도 고려해야 합니다.

특히 bulkSize 옵션을 더 크게 지정한 경우에는 더욱 유의해야 합니다.

7. httpClient의 로깅 관련 경고 메시지

http 프로토콜을 사용하는 경우, 애플리케이션이 시작할 때 아래와 같은 로그가 생깁니다.

이는 httpClient 라이브러리가 apache logging 프레임워크를 사용하기 때문이며, 여기서 생성된 로그는 root logger에 남습니다.

SLF4J: The following loggers will not work because they were created
SLF4J: during the default configuration phase of the underlying logging system.
SLF4J: See also http://www.slf4j.org/codes.html#substituteLogger
SLF4J: org.apache.http.impl.conn.PoolingClientConnectionManager
SLF4J: org.apache.http.impl.conn.DefaultClientConnectionOperator
SLF4J: org.apache.http.impl.client.DefaultHttpClient

""에 대한 건이 검색되었습니다.

    ""에 대한 검색 결과가 없습니다.

    처리중...