• 2019年8月23日金曜日
アリスト戦記
アリスト戦記 https://blog.aristo-solutions.net/2019/08/log4j.html

log4jのエラーログの出力先をクラス指定で別ファイルにしたい!!

Javaにおけるログ出力ツールの金字塔として君臨しているlog4jだが、「特定のログだけ違うファイルに出力したい」という需要が偶にある。

これの実現方法についての解説です。

背景

システム開発の運用保守においては、ログ監視というものが重要になる。
システムエラーの発生を検知したら、それを運用保守担当の人間に連絡する為だ。

僕も若き日には運用保守を担当しており、深夜0時に電話が掛かってくることくらい朝飯前だった。(;´-ω-`)

この運用で問題となってくるのが、検知不要なものが検知されてしまうという事象が発生することだ。

例えば、僕の経験の限りだと、ユーザーにタイミング悪く×ボタンを押されてしまうとシステムエラーになる、とかね。
ネットワークが切断された、とかそんな感じのエラーだったと思う。

ユーザーが×ボタンを押してブラウザを閉じた結果発生するエラーであれば、ユーザは既に画面を閉じているから、システムエラーになったとしても何の問題も無い。
しかし、ログ上はシステムエラーになっているから、システムエラーとして検知されて、日中に何度もに電話が掛かってきてしまう。

これが運用上、非常に面倒でウンザリすることになる。

この問題を解決したい、というのが今回の記事の趣旨だ。

検知のカラクリ

では、そもそも「検知」とはどういうカラクリで行われているのだろうか?

ログ監視ツールは色々あるけど、基本はGrepだ。


2019-08-23 11:34:53 ERROR: [net.aristo.template.batch.exe.LogTargetExecuter:56][doStart] - エラーが発生しました。 - [main]


ログファイルの中からログ文字列を走査し、特定のキーワードを検出したら通知する、というロジックで監視が組まれていることが一般的である。

「特定のキーワード」というのは、ケースバイケースだ。
この例では「ERROR」だけど、システムに依っては「FATAL」だったりする。

いずれにせよ、予め「この文字列が出たらエラーだ」というキーワードを前もって決めておいて、それに即してログを出力することになる。

だけど、実際の運用では「キーワードが出ちゃってるんだけど、検知からは対象外にしたい」という需要もある。

そういう時にどうすれば良いか?

対処方法

対処方法1.ログレベルを変える

正攻法はこれ。
ログレベルを変える。

logger.error("エラーが発生しました。");

こういう風に実装されちゃっているものを、

logger.warn("エラーが発生しました。");

こういう風にすれば、出力されるログは以下のようになる。

2019-08-23 11:52:16 WARN : [net.aristo.template.batch.exe.LogTargetExecuter:56][doStart] - エラーが発生しました。 - [main]

キーワードであった「ERROR」が無くなるから検知されることは無くなる。
これが正攻法だ。

しかしこのやり方には制限がある。
自分で実装しているログだったら変えられるけど、フレームワークの中から出てくるログは変えられない。

だから、「フレームワークの中から出力されているログをwarnにしてくれ」という要望は物理的に対応不能なのだ。

ではどうすれば良いか?
それが対処方法2である。

対処方法2.ファイルを変える

フレームワークの中から出てくるエラーのエラーレベルを変えることは出来ないんだけど、ファイルを変えることは出来る

まず例として、以下のように検知したくないログクラスがあるとする。

public class LogNotTargetService {

   /** logger */
   private static final Logger logger = LoggerFactory.getLogger(LogNotTargetService.class);

   public void log() {

      logger.error("エラーが発生しましたが、問題ありません。");

   }
}

その上で、以下のようにlogback.xmlのAppenderに「監視用ファイル」と「監視対象外ファイル」の2つの設定を作る。

   <!-- ERRORログ -->
   <appender name="ERROR"
      class="ch.qos.logback.core.FileAppender">
      <file>${LOG_DIR}/error.log</file>
      <filter class="ch.qos.logback.classic.filter.LevelFilter">
         <level>ERROR</level>
         <onMatch>ACCEPT</onMatch>
         <onMismatch>DENY</onMismatch>
      </filter>
      <encoder>
         <charset>UTF-8</charset>
         <pattern>${PATTERN}</pattern>
      </encoder>
   </appender>

   <!-- ERRORログ・検知対象外 -->
   <appender name="ERROR_NOT_TARGET"
      class="ch.qos.logback.core.FileAppender">
      <file>${LOG_DIR}/error_not_target.log</file>
      <filter class="ch.qos.logback.classic.filter.LevelFilter">
         <level>ERROR</level>
         <onMatch>ACCEPT</onMatch>
         <onMismatch>DENY</onMismatch>
      </filter>
      <encoder>
         <charset>UTF-8</charset>
         <pattern>${PATTERN}</pattern>
      </encoder>
   </appender>

そして、検知したくないログが出で来るクラスを、検知対象外ファイルの方にぶら下げる。


<logger name="net.aristo.template.batch.service.LogNotTargetService" additivity="true" level="ERROR">
   <appender-ref ref="ERROR_NOT_TARGET" />
</logger>

これでOKだ。

制限事項

なお、「対処方法2.ファイルを変える」のやり方は、最小粒度がクラス単位である。

だから、同じクラスの中から複数種類のログが出ており、そのうち1つだけを対象外にする、というやり方は出来ない。
クラス単位で指定。

これがlog4jの仕様だ。

間違えて「検知しなければいかなかったログを対象外にしちゃった!!」というのはマズいので注意。

logback.xml全体

全体としては以下のlogback.xmlの書き方で検証を行いました。

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE logback>
<configuration>

   <!-- 変数定義 -->
   <property name="LOG_DIR" value="R:/log/JavaSample" />
   <property name="PATTERN"
      value="%d{yyyy-MM-dd HH:mm:ss} %-5level: [%logger:%L][%M] - %msg - [%t]%n" />

   <!-- ログ・コンソール出力 -->
   <appender name="STOUT"
      class="ch.qos.logback.core.ConsoleAppender">
      <filter class="ch.qos.logback.classic.filter.LevelFilter">
         <level>TRACE</level>
      </filter>
      <encoder>
         <charset>UTF-8</charset>
         <pattern>${PATTERN}</pattern>
      </encoder>
   </appender>

   <!-- 全ログ -->
   <appender name="ALL"
      class="ch.qos.logback.core.rolling.RollingFileAppender">
      <file>${LOG_DIR}/all.log</file>
      <rollingPolicy
         class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
         <fileNamePattern>${LOG_DIR}/all.log.%i.log</fileNamePattern>
         <minIndex>0</minIndex>
         <maxIndex>9</maxIndex>
      </rollingPolicy>
      <triggeringPolicy
         class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
         <maxFileSize>500KB</maxFileSize>
      </triggeringPolicy>
      <filter class="ch.qos.logback.classic.filter.LevelFilter">
         <level>ALL</level>
         <onMatch>ACCEPT</onMatch>
         <onMismatch>ACCEPT</onMismatch>
      </filter>
      <encoder>
         <pattern>${PATTERN}</pattern>
      </encoder>
   </appender>

   <!-- TRACEログ -->
   <appender name="TRACE"
      class="ch.qos.logback.core.rolling.RollingFileAppender">
      <file>${LOG_DIR}/trace.log</file>
      <rollingPolicy
         class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
         <fileNamePattern>${LOG_DIR}/trace-%d{yyyyMMdd}.log</fileNamePattern>
         <maxHistory>7</maxHistory>
      </rollingPolicy>
      <filter class="ch.qos.logback.classic.filter.LevelFilter">
         <level>TRACE</level>
         <onMatch>ACCEPT</onMatch>
         <onMismatch>DENY</onMismatch>
      </filter>
      <encoder>
         <charset>UTF-8</charset>
         <pattern>${PATTERN}</pattern>
      </encoder>
   </appender>

   <!-- DEBUGログ -->
   <appender name="DEBUG"
      class="ch.qos.logback.core.rolling.RollingFileAppender">
      <file>${LOG_DIR}/debug.log</file>
      <rollingPolicy
         class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
         <fileNamePattern>${LOG_DIR}/debug-%d{yyyyMMdd}.log</fileNamePattern>
         <maxHistory>7</maxHistory>
      </rollingPolicy>
      <filter class="ch.qos.logback.classic.filter.LevelFilter">
         <level>DEBUG</level>
         <onMatch>ACCEPT</onMatch>
         <onMismatch>DENY</onMismatch>
      </filter>
      <encoder>
         <charset>UTF-8</charset>
         <pattern>${PATTERN}</pattern>
      </encoder>
   </appender>

   <!-- INFOログ -->
   <appender name="INFO"
      class="ch.qos.logback.core.rolling.RollingFileAppender">
      <file>${LOG_DIR}/info.log</file>
      <rollingPolicy
         class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
         <fileNamePattern>${LOG_DIR}/info-%d{yyyyMMdd}.log</fileNamePattern>
         <maxHistory>7</maxHistory>
      </rollingPolicy>
      <filter class="ch.qos.logback.classic.filter.LevelFilter">
         <level>INFO</level>
         <onMatch>ACCEPT</onMatch>
         <onMismatch>DENY</onMismatch>
      </filter>
      <encoder>
         <charset>UTF-8</charset>
         <pattern>${PATTERN}</pattern>
      </encoder>
   </appender>

   <!-- WARNログ -->
   <appender name="WARN"
      class="ch.qos.logback.core.rolling.RollingFileAppender">
      <file>${LOG_DIR}/warn.log</file>
      <rollingPolicy
         class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
         <fileNamePattern>${LOG_DIR}/warn-%d{yyyyMMdd}.log</fileNamePattern>
         <maxHistory>7</maxHistory>
      </rollingPolicy>
      <filter class="ch.qos.logback.classic.filter.LevelFilter">
         <level>WARN</level>
         <onMatch>ACCEPT</onMatch>
         <onMismatch>DENY</onMismatch>
      </filter>
      <encoder>
         <charset>UTF-8</charset>
         <pattern>${PATTERN}</pattern>
      </encoder>
   </appender>

   <!-- ERRORログ -->
   <appender name="ERROR"
      class="ch.qos.logback.core.FileAppender">
      <file>${LOG_DIR}/error.log</file>
      <filter class="ch.qos.logback.classic.filter.LevelFilter">
         <level>ERROR</level>
         <onMatch>ACCEPT</onMatch>
         <onMismatch>DENY</onMismatch>
      </filter>
      <encoder>
         <charset>UTF-8</charset>
         <pattern>${PATTERN}</pattern>
      </encoder>
   </appender>

   <!-- ERRORログ・検知対象外 -->
   <appender name="ERROR_NOT_TARGET"
      class="ch.qos.logback.core.FileAppender">
      <file>${LOG_DIR}/error_not_target.log</file>
      <filter class="ch.qos.logback.classic.filter.LevelFilter">
         <level>ERROR</level>
         <onMatch>ACCEPT</onMatch>
         <onMismatch>DENY</onMismatch>
      </filter>
      <encoder>
         <charset>UTF-8</charset>
         <pattern>${PATTERN}</pattern>
      </encoder>
   </appender>

   <!-- ロガー・root設定 -->
   <root level="ALL">
      <appender-ref ref="STOUT" />
      <appender-ref ref="ALL" />
      <appender-ref ref="TRACE" />
      <appender-ref ref="DEBUG" />
      <appender-ref ref="INFO" />
      <appender-ref ref="WARN" />
      <appender-ref ref="ERROR" />
   </root>

   <!-- ロガー・パッケージ別設定 -->
   <logger name="net.solutions.aristo" additivity="true"
      level="INFO" />
   <logger name="org.springframework" additivity="true"
      level="WARN" />
   <logger name="javax.management" additivity="true" level="WARN" />

   <logger name="net.aristo.template.batch.service.LogNotTargetService" additivity="true" level="ERROR">
      <appender-ref ref="ERROR_NOT_TARGET" />
   </logger>


</configuration>

0 件のコメント:

コメントを投稿