Log4j iş parçacığı güvenli değil mi?

Question

(Bu SLES11 üzerinde, Java 7, Tomcat 6, log4j-1.2.16)

Farklı günlük dosyalarına farklı şeyler yazmak için log4j kullanıyoruz. Bu kodu miras aldım, bu yüzden iyi ya da kötüler için genel yapı şimdilik kalmak için burada.

Kaydedici iki günlük dosyası oluşturacaktır: main.log ve stats.log. Her iki kaydediciye ayrı çağrılarla belirli bir istatistik mesajı kaydedilir (aşağıda göreceksiniz) ve bir sürü başka şey ana günlüğe kaydedilir.

Tüm kodlarımızda Log.logMain(someMessageToLog); gibi öğeleri göreceksiniz.

ana kaydedici adı main olan

String statsMessage = createStatsMessage(); 
Log.logMain(statsMessage); 
Log.logStats(statsMessage); 

, istatistik kaydedici adı stats bağlıdır: (çoklu iş parçacığı tarafından yürütülür) bizim kodunda tek yerde şu var. Sorun şu ki, ağır yük altında, main.log dizgisinde stats INFO dizgisine sahip çizgiler görüyoruz. main.log'daki her şey sadece main INFO olmalıdır, çünkü bu dosya için günlüğe kaydedilen tek günlüğü kaydeder, ayrıca bazı satırlarda karma çıkışı görürüz. Bu, iş parçacığı güvenliği sorunu gibi görünüyor, ancak log4j belgeleri, log4j'nin iş parçacığı için güvenli olduğunu söylüyor. : - İşte

2012-03-21 16:01:34,7742012-03-21 16:01:34,774| | stats main INFO [INFO http-8080-18]: [message redacted]. 
2012-03-21 16:01:36,380| main 2012-03-21 16:01:36,380| INFO [stats INFO http-8080-15]: [message redacted]. 
2012-03-21 16:01:37,465| main INFO 2012-03-21 16:01:37,465 [| stats http-8080-1]: [message redacted]. 

Log sınıf (o diğer kaydediciler bir demet, tüm bu benzer kurmak aslında orada sadece aşağı soyulmuş söz konusu günlükçüleri göster) oluyor: İşte ne demek istediğimi bir örnek

import org.apache.log4j.*; 

import java.io.IOException; 

final public class Log 
{ 
    private static final String LOG_IDENTIFIER_MAINLOG = "main"; 
    private static final String LOG_IDENTIFIER_STATSLOG = "stats"; 

    private static final String MAIN_FILENAME = "/var/log/app_main.log"; 
    private static final String STATS_FILENAME = "/var/log/app_stats.log"; 

    private static final int BACKUP_INDEX = 40; 
    private static final String BACKUP_SIZE = "10MB"; 

    private static final PatternLayout COMMON_LAYOUT = 
     new PatternLayout("%d| %c %-6p [%t]: %m.%n"); 

    private static Logger mainLogger; 
    private static Logger statsLogger; 

    public static void init() { 
     init(MAIN_FILENAME, STATS_FILENAME); 
    } 

    public static void init(String mainLogFilename, 
          String statsLogFilename) { 
     mainLogger = initializeMainLogger(mainLogFilename); 
     statsLogger = initializeStatsLogger(statsLogFilename); 
    } 

    public static void logMain(String message) { 
     if (mainLogger != null) { 
      mainLogger.info(message); 
     } 
    } 

    public static void logStats(String message) { 
     if (statsLogger != null) { 
      statsLogger.info(message); 
     } 
    } 

    private static Logger getLogger(String loggerIdentifier) { 
     Logger logger = Logger.getLogger(loggerIdentifier); 
     logger.setAdditivity(false); 
     return logger; 
    } 

    private static boolean addFileAppender(Logger logger, 
              String logFilename, 
              int maxBackupIndex, 
              String maxSize) { 
     try { 
      RollingFileAppender appender = 
       new RollingFileAppender(COMMON_LAYOUT, logFilename); 
      appender.setMaxBackupIndex(maxBackupIndex); 
      appender.setMaxFileSize(maxSize); 
      logger.addAppender(appender); 
     } 
     catch (IOException ex) { 
      ex.printStackTrace(); 
      return false; 
     } 
     return true; 
    } 

    private static Logger initializeMainLogger(String filename) { 
     Logger logger = getLogger(LOG_IDENTIFIER_MAINLOG); 
     addFileAppender(logger, filename, BACKUP_INDEX, BACKUP_SIZE); 
     logger.setLevel(Level.INFO); 
     return logger; 
    } 

    private static Logger initializeStatsLogger(String filename) { 
     Logger logger = getLogger(LOG_IDENTIFIER_STATSLOG); 
     addFileAppender(logger, filename, BACKUP_INDEX, BACKUP_SIZE); 
     logger.setLevel(Level.INFO); 
     return logger; 
    } 

} 

---

Güncelleme: İşte

arkadaşları var

final public class Stress 
{ 
    public static void main(String[] args) throws Exception { 
     if (args.length != 2) { 
      Log.init(); 
     } 
     else { 
      Log.init(args[0], args[1]); 
     } 

     for (;;) { 
      // I know Executors are preferred, but this 
      // is a quick & dirty test program 
      Thread t = new Thread(new TestLogging()); 
      t.start(); 
     } 
    } 

    private static final class TestLogging implements Runnable 
    { 
     private static int counter = 0; 

     @Override 
     public void run() { 
      String msg = new StringBuilder("Count is: ") 
       .append(counter++).toString(); 

      Log.logMain(msg); 
      Log.logStats(msg); 

      try { 
       Thread.sleep(1); 
      } 
      catch (InterruptedException e) { 
       Log.logMain(e.getMessage()); 
      } 
     } 
    } 
} 

Ve günlüklerde bazı örnek çıktı:

$ grep stats main.log  
2012-03-23 15:30:35,919| stats 2012-03-23 15:30:35,919| main INFO INFO [ [Thread-313037]: Thread-313036]: Count is: 312987. 
2012-03-23 15:30:35,929| stats INFO [Thread-313100]: Count is: 313050. 
2012-03-23 15:30:35,937| stats INFO [Thread-313168]: Count is: 313112. 
2012-03-23 15:30:35,945| stats INFO [Thread-313240]: Count is: 313190. 
2012-03-23 15:30:35,946| stats INFO [Thread-313251]: Count is: 313201. 
2012-03-23 15:30:35,949| stats INFO [2012-03-23 15:30:35,949| main INFO Thread-313281]: Count is: 313231. 
2012-03-23 15:30:35,954| stats INFO [Thread-313331]: Count is: 313281. 
2012-03-23 15:30:35,956| 2012-03-23 15:30:35,956stats | main INFOINFO [ [Thread-313356]: Count is: 313306. 
2012-03-23 15:30:35,9562012-03-23 15:30:35,956| main | INFO stats [INFOThread-313359]: Count is: 313309. 
2012-03-23 15:30:35,962| stats INFO 2012-03-23 15:30:35,962| main INFO [Thread-313388]: [Count is: 313338. 

ve

$ grep main stats.log 
2012-03-23 15:30:35,913| 2012-03-23 15:30:35,913| main INFO [Thread-312998]: Count is: 312948. 
2012-03-23 15:30:35,915| main INFO [Thread-313014]: Count is: 312964. 
2012-03-23 15:30:35,919| stats 2012-03-23 15:30:35,919| main INFO INFO [ [Thread-313037]: Thread-313036]: Count is: 312987. 
2012-03-23 15:30:35,931| main INFO [Thread-313116]: Count is: 313066. 
2012-03-23 15:30:35,947| main INFO [2012-03-23 15:30:35,947Thread-313264]: | Count is: 313214. 
2012-03-23 15:30:35,949| stats INFO [2012-03-23 15:30:35,949| main INFO Thread-313281]: Count is: 313231. 
2012-03-23 15:30:35,956| 2012-03-23 15:30:35,956stats | main INFOINFO [ [Thread-313356]: Count is: 313306. 
2012-03-23 15:30:35,9562012-03-23 15:30:35,956| main | INFO stats [INFOThread-313359]: Count is: 313309. 
2012-03-23 15:30:35,962| stats INFO 2012-03-23 15:30:35,962| main INFO [Thread-313388]: [Count is: 313338. 

için (benim için en azından) Yukarıdaki Log sınıf sorunu yeniden edecektir İttle programı 145516 satırlık bir main.log dosyasından çıktığında, "istatistik" in 2452 katına çıktı. Yani nadir değil ama her zaman olduğu gibi değil (ve tabii ki bu test oldukça aşırı).

Answer 1

http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/PatternLayout.html

Yukarıdaki API linke göre iki appenders arasında PatternLayout paylaşıyorsunuz:

Bu kod senkronizasyon ve org bulunmayan diğer sorunları olduğu bilinmektedir. apache.log4j.EnhancedPatternLayout. EnhancedPatternLayout, PatternLayout tercihinde kullanılmalıdır. EnhancedPatternLayout, log4j ekstralar arkadaşına dağıtılır.

Yani her appender