Log4jで複数プロセスから同一ファイルへの出力

ログ出力ライブラリでデファクトスタンダードLog4jですが、
複数プロセスからの同一ファイル書き込みの際、
ファイルロックの取り合いでローテションのタイミングなどで
ファイルが壊れたり、正常に書き込めなかったりと問題が満載です。


そんな時にやくに立つのが、SocketServerです。
Log4jのライブラリ内にSocketServerが存在します。
Log4jのものは使うなと良く噂に聞いていたのですが、ソースをきちんと
読んで判断したかったので実際に読んでみました*1


Log4j内には、「SocketServer」、「SimpleSocketServer」の2つが存在します。
以下はSimpleSocketSererのソース

  public static void main(String argv[]) {
    if(argv.length == 2) {
      init(argv[0], argv[1]);
    } else {
      usage("Wrong number of arguments.");
    }
    
    try {
      cat.info("Listening on port " + port);
      ServerSocket serverSocket = new ServerSocket(port);
      while(true) {
	cat.info("Waiting to accept a new client.");
	Socket socket = serverSocket.accept();
	cat.info("Connected to client at " + socket.getInetAddress());
	cat.info("Starting new socket node.");
	new Thread(new SocketNode(socket,
				  LogManager.getLoggerRepository())).start();
      }
    } catch(Exception e) {
      e.printStackTrace();
    }
  }


  static void  usage(String msg) {
    System.err.println(msg);
    System.err.println(
      "Usage: java " +SimpleSocketServer.class.getName() + " port configFile");
    System.exit(1);
  }

  static void init(String portStr, String configFile) {
    try {
      port = Integer.parseInt(portStr);
    } catch(java.lang.NumberFormatException e) {
      e.printStackTrace();
      usage("Could not interpret port number ["+ portStr +"].");
    }
   
    if(configFile.endsWith(".xml")) {
      DOMConfigurator.configure(configFile);
    } else {
      PropertyConfigurator.configure(configFile);
    }
  }
}

とまあ、待ち受けるサーバ側としてよく見る普通の形。
SocketServerの方も基本的には同じ。
Log4jなんで、設定ファイル読み込みなどがあるのが違いだけ。


ただ、ServerSocketのクローズ処理がないのが気になる・・・
さて、実際のログ出力処理は、

new Thread(new SocketNode(socket,
	  LogManager.getLoggerRepository())).start();

この部分。

SocketNodeは、以下のようなソース

public class SocketNode implements Runnable {

  Socket socket;
  LoggerRepository hierarchy;
  ObjectInputStream ois;

  static Logger logger = Logger.getLogger(SocketNode.class);

  public SocketNode(Socket socket, LoggerRepository hierarchy) {
    this.socket = socket;
    this.hierarchy = hierarchy;
    try {
      ois = new ObjectInputStream(
                         new BufferedInputStream(socket.getInputStream()));
    }
    catch(Exception e) {
      logger.error("Could not open ObjectInputStream to "+socket, e);
    }
  }

  public void run() {
    LoggingEvent event;
    Logger remoteLogger;

    try {
      if (ois != null) {
          while(true) {
	        // read an event from the wire
	        event = (LoggingEvent) ois.readObject();
	        // get a logger from the hierarchy. The name of the logger is taken to be the name contained in the event.
	        remoteLogger = hierarchy.getLogger(event.getLoggerName());
	        //event.logger = remoteLogger;
	        // apply the logger-level filter
	        if(event.getLevel().isGreaterOrEqual(remoteLogger.getEffectiveLevel())) {
	        // finally log the event as if was generated locally
	        remoteLogger.callAppenders(event);
	      }
        }
      }
    } catch(java.io.EOFException e) {
      logger.info("Caught java.io.EOFException closing conneciton.");
    } catch(java.net.SocketException e) {
      logger.info("Caught java.net.SocketException closing conneciton.");
    } catch(IOException e) {
      logger.info("Caught java.io.IOException: "+e);
      logger.info("Closing connection.");
    } catch(Exception e) {
      logger.error("Unexpected exception. Closing conneciton.", e);
    } finally {
      if (ois != null) {
         try {
            ois.close();
         } catch(Exception e) {
            logger.info("Could not close connection.", e);
         }
      }
      if (socket != null) {
        try {
          socket.close();
        } catch(IOException ex) {
        }
      }
    }
  }
}

さて、ここで気になるのがまたSocketのクローズ処理がないこと。
ちなみに、

      if (ois != null) {
          while(true) {
	        // read an event from the wire
	        event = (LoggingEvent) ois.readObject();
	        // get a logger from the hierarchy. The name of the logger is taken to be the name contained in the event.
	        remoteLogger = hierarchy.getLogger(event.getLoggerName());
	        //event.logger = remoteLogger;
	        // apply the logger-level filter
	        if(event.getLevel().isGreaterOrEqual(remoteLogger.getEffectiveLevel())) {
	        // finally log the event as if was generated locally
	        remoteLogger.callAppenders(event);
	      }
        }
      }

while(true)って無限ループ?
なんで・・・
CPU食いまくりなんじゃないかと思って、実際に動かしてみたら全然食わない・・・
色々とデバッグで動作を確認したら、
Log4jを使用しているクライアント側の最初の要求以降、通信はずっと開きっぱなし。
まあ、確かに通信接続切断を頻繁にしてたらコストがかかってしょうがないので。
ようは、下記部分で待つ。

event = (LoggingEvent) ois.readObject();

とれたら処理を繰り返す。
クローズ処理がないのは、クライアント側が終了したタイミングで通信が切られている。
なんで、クローズ処理をする必要がないってことで実装してないのかな!?
でも、普通は入れるよなww


とまあこんな感じでした。
少し手を加える程度で十分使えると感じました。
やはり自分で読んで確認してみるのが一番ですね。


ちなみに、クライアント側Log4jの設定ファイルでAppendarの数だけ個々にSocketを開くので
ご注意ください。

*1:log4j-1.2.15のソース