Logback SDK v2 の使用方法

この章はEffective Log Search & Analytics Logback SDKを使用する方法を説明するために作成されました。NELOはEffective Log Search & Analyticsのプロジェクトコードネームです。

NELO2 Logback SDK dependencyの追加

以下のようにDependencyを追加します。

圧縮ファイル解除後、coreモジュールとlogbackモジュールの経路を<systemPath>に追加します。

<dependencies>
        <dependency>
            <groupId>nelo2-java-sdk-core</groupId>
            <artifactId>nelo2-java-sdk-core</artifactId>
            <version>1.6.6</version>
            <scope>system</scope>
            <systemPath>/nelo2-java-sdk-core-1.6.6.jar</systemPath>
        </dependency>
        <dependency>
            <groupId>nelo2-java-sdk</groupId>
            <artifactId>nelo2-java-sdk-logback</artifactId>
            <version>1.6.6</version>
            <scope>system</scope>
            <systemPath>/nelo2-java-sdk-logback-1.6.6.jar</systemPath>
        </dependency>
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
            <version>1.1.7</version>
        </dependency>
        <dependency>
            <groupId>org.apache.thrift</groupId>
            <artifactId>libthrift</artifactId>
            <version>0.9.3</version>
        </dependency>
        <dependency>
            <groupId>org.apache.httpcomponents</groupId>
            <artifactId>httpclient</artifactId>
            <version>4.2.6</version>
        </dependency>
        <dependency>
            <groupId>com.fasterxml.jackson.core</groupId>
            <artifactId>jackson-databind</artifactId>
            <version>2.3.1</version>
        </dependency>
</dependencies>

備考

  • この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="プロジェクトID"></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: プロジェクトID。Effective Log Search & Analyticsのプロジェクト情報で生成したプロジェクトのIDを確認できます。

  • 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モードを使用する場合、1バルクリクエストに送信される最大ログ数、 基本値1000, 最大値100000

  • bulkInterval : bulkモードを使用する場合バルク要請を呼び出すことになる周期、デフォルト値1000ms(1秒)、最大値10000ms(10秒)

  • alwaysIncludeLocation : SDKがすべてのログに Locationフィールドを追加するかどうか、デフォルトはtrueです。

    • false : logLevelが ERRORであるログの Locationフィールドを確認および設定します。
    • true : すべてのログの Locationフィールドを確認して設定します。 これは、 falseと比較してロギングパフォーマンスに悪影響を与える可能性があります。
  • mdcConversionRule : MDCキーの名前を変更するためのルール。

    • format: key1:newKey1;key2:newkey2;...
      例) mdcConversionRuleを time:date;fullname:name に設定します。このルールはMDCキー timeをdateに、 fullnameが存在する場合はそれらをnameに名前変更します。

bulk/single

Effective Log Search & Analytics logback SDKはログの転送を1件ずつ送信する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に比べてsinglモードでより大きく現れます。 従って基本値である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="プロジェクト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" />
    </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にログを転送したが、これをウェブで確認できない場合

プロジェクトIDが正しいか確認します。プロジェクトIDが正しくない場合、ウェブダッシュボードでログを確認できません。

また、実際エラーデータが転送されたか確認します。設定ファイル(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分のメモリーを占めます。

Javaプロセスを起動する際、最大のヒップを -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

に対する検索結果は~件です。 ""

    に対する検索結果がありません。 ""

    処理中...