大事なログを取り逃さない 〜タイムシフトロガー〜

重大なエラーが発生した時には、ログを詳細に出力しておきたいが、でも本番環境でログレベルを常時DEBUGしておくわけにはいかない…
そんなときでもタイムシフトロガーがあれば大丈夫！ エラーが発生したひとのログをある一定時間遡って詳細なレベルで取得できます。

というものを作ってみました。

仕組みですが、一定期間だけログを保管しておき、しきい値を超えたら溜め込んでいる詳細なログを吐き出す、というものです。

log4jのSocketAppenderを1つ追加してもらって、タイムシフトログサーバに向けます。そしてこれはDEBUGレベルにしておきます。

<appender name="timeshift" class="org.apache.log4j.net.SocketAppender">
    <param name="RemoteHost" value="logserver"/>
    <param name="Port" value="8888"/>
    <param name="ReconnectionDelay" value="1000"/>
    <param name="Threshold" value="DEBUG"/>
</appender>

利用アプリ側ではユーザの識別IDをNDCに設定しておいてる想定ですが、やることはこれだけです。既存のアプリに極力手を入れずに、ログのタイムシフト再生を手にすることができます。

そして、タイムシフトログサーバを起動します。

% lein run

タイムシフトログサーバは、Apache Flumeで動いていて、SocketAppenderからのイベントを受けるSourceは、RedisにログイベントをユーザIDをキーに溜め込んでいきます。そしてしきい値以上のレベルのログイベントが到着すると、そのユーザIDに関するログをまとめて、Flumeのチャネルに流し込みます。

Sink側は自由に設定すればよいのですが、

(defsink print-sink
  :process (fn [event]
             (let [odis (ObjectDecoderInputStream. (ByteArrayInputStream. (.getBody event)))
                   logs (.readObject odis)]
               (println "==================================")
               (doseq [log logs]
                 (.append console-appender log))
               (println "=================================="))))

core.cljに定義してあるようにClojure側で以下のようなSinkを作っておくと、

==================================
USER01 2014/07/16 19:49:07.269 ERROR Main - jojo
java.lang.Exception
        at net.unit8.timeshift.examples.Main$1.run(Main.java:35)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:724)
==================================
==================================
USER03 2014/07/16 19:49:07.265 DEBUG Main - jojo
java.lang.Exception
        at net.unit8.timeshift.examples.Main$1.run(Main.java:35)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:724)
pool-1-thread-3 2014/07/16 19:49:07.267 ERROR Main - jojo
java.lang.Exception
        at net.unit8.timeshift.examples.Main$1.run(Main.java:35)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:724)
==================================

このような感じでユーザID単位でそれまでのログを全部出力出来ます。

ちなみにFlumeの設定はJavaのpropertiesで書かなきゃいけなかったり、カスタムSourceやカスタムSinkを作ろうとするとJavaで書いてプロパティに設定して…など、何かと面倒なのですが、clj-flume-nodeを使うと非常に簡単にFlumeを設定・起動でき、カスタムSinkも上記のように楽々です。