log4cxxのDailyRollingFileAppender

前回なぜかファイルがrollingされない件に遭遇したのでちょっとソースコードを追いかけてみた。

rolling関係処理を追いかけたところ、RollingFileAppenderSkeleton::subAppend() @ rollingfileappender.cppがキモっぽい。

void RollingFileAppenderSkeleton::subAppend(const LoggingEventPtr& event, Pool& p) {
  // The rollover check must precede actual writing. This is the
  // only correct behavior for time driven triggers.
  if (
    triggeringPolicy->isTriggeringEvent(
        this, event, getFile(), getFileLength())) {
    //
    //   wrap rollover request in try block since
    //    rollover may fail in case read access to directory
    //    is not provided.  However appender should still be in good
    //     condition and the append should still happen.
    try {
      rollover(p);
    } catch (std::exception& ex) {
        LogLog::warn(LOG4CXX_STR("Exception during rollover attempt."));
    }
  }
  FileAppender::subAppend(event, p);
}

ファイルの更新判定処理は timebasedrollingpolicy.cpp の TimeBasedRollingPolicy::isTriggeringEvent() が呼ばれていて

bool TimeBasedRollingPolicy::isTriggeringEvent(
  Appender* /* appender */,
  const log4cxx::spi::LoggingEventPtr& /* event */,
  const LogString& /* filename */,
  size_t /* fileLength */)  {
    return apr_time_now() > nextCheck;
}

現在時刻がnextCheck以降なら更新を試みるっぽい。
(isTriggeringEvent() が true を返す時だけ rollover() が呼ばれる。triggeringPolicy にはDailyRollingFileAppender の初期化処理で TimeBasedRollingPolicy が設定されている)


nextCheckはTimeBasedRollingPolicy::initialize()の最初で

  apr_time_t n = apr_time_now();
  nextCheck = ((n / APR_USEC_PER_SEC) + 1) * APR_USEC_PER_SEC;

としてあるので現在時刻をベースとした時間になっている。

つまりファイルの時刻を見ているわけではないのでファイルが古くてもrollingしないことに。
あと、TimeBasedRollingPolicy::isTriggeringEvent()を見る限り、どうやらファイルサイズによるrollingもないっぽい。


DailyRollingFileAppenderが想定している使い方はずっとアプリケーションが動きっぱなしの状態で大量のログを吐きだすから途中でログファイルをrollingするって使い方になりそう。
古いログファイルがあれば何世代かバックアップを取り、ファイルサイズが大きくなった場合も新しいファイルにするって機能を期待したのに当てが外れた。う〜ん。これなら普通にRollingFileAppenderでいいかも。こっちは最低限ファイルサイズでrollingできるから巨大ファイルが残る心配がなさそうだし。