Log4j：事件出現在錯誤的日誌文件中

Question

爲了能夠記錄和跟蹤一些事件，我已經爲我的Java項目添加了一個LoggingHandler類。在這個類的內部，我使用了兩個不同的log4j記錄器實例 - 一個用於記錄事件，另一個用於將事件追蹤到不同的文件中。類的初始化塊看起來是這樣的：

public void initialize() 
{ 
    System.out.print("starting logging server ..."); 

    // create logger instances 
    logLogger = Logger.getLogger("log"); 
    traceLogger = Logger.getLogger("trace"); 

    // create pattern layout 
    String conversionPattern = "%c{2} %d{ABSOLUTE} %r %p %m%n"; 
    try 
    { 
     patternLayout = new PatternLayout(); 
     patternLayout.setConversionPattern(conversionPattern); 
    } 
    catch (Exception e) 
    { 
     System.out.println("error: could not create logger layout pattern"); 
     System.out.println(e); 
     System.exit(1); 
    } 

    // add pattern to file appender 
    try 
    { 
     logFileAppender = new FileAppender(patternLayout, logFilename, false); 
     traceFileAppender = new FileAppender(patternLayout, traceFilename, false); 
    } 
    catch (IOException e) 
    { 
     System.out.println("error: could not add logger layout pattern to corresponding appender"); 
     System.out.println(e); 
     System.exit(1); 
    } 

    // add appenders to loggers 
    logLogger.addAppender(logFileAppender); 
    traceLogger.addAppender(traceFileAppender); 

    // set logger level 
    logLogger.setLevel(Level.INFO); 
    traceLogger.setLevel(Level.INFO); 

    // start logging server 
    loggingServer = new LoggingServer(logLogger, traceLogger, serverPort, this); 
    loggingServer.start(); 

    System.out.println(" done"); 
} 

要確保只有唯一的線程在同一時間使用日誌記錄器實例的功能/跟蹤的方法調用.INFO的測井方法（）內一個同步塊。一個例子是這樣的：

public void logMessage(String message) 
{ 
    synchronized (logLogger) 
    { 
     if (logLogger.isInfoEnabled() && logFileAppender != null) 
     { 
      logLogger.info(instanceName + ": " + message); 
     } 
    } 
} 

如果看我的日誌文件，我看到，有時候一個事件出現在了錯誤的文件。舉個例子：

trace 10:41:30,773 11080 INFO masterControl(192.168.2.21): string broadcast message was pushed from 1267093 to vehicle 1055293 (slaveControl 1) 
trace 10:41:30,784 11091 INFO masterControl(192.168.2.21): string broadcast message was pushed from 1156513 to vehicle 1105792 (slaveControl 1) 
trace 10:41:30,796 11103 INFO masterControl(192.168.2.21): string broadcast message was pushed from 1104306 to vehicle 1055293 (slaveControl 1) 
trace 10:41:30,808 11115 INFO masterControl(192.168.2.21): vehicle 1327879 was pushed to slave control 1 
10:41:30,808 11115 INFO masterControl(192.168.2.21): string broadcast message was pushed from 1101572 to vehicle 106741 (slaveControl 1) 
trace 10:41:30,820 11127 INFO masterControl(192.168.2.21): string broadcast message was pushed from 1055293 to vehicle 1104306 (slaveControl 1) 

我覺得現在的問題occures每次兩個事件發生在同一時間（這裏：10：41：30808）。有人有一個想法如何解決我的問題？我已經嘗試過的方法調用後添加一個sleep（），但這並沒有幫助...

BR，

馬庫斯

編輯：

logtrace 11:16:07,75511:16:07,755 1129711297 INFOINFO masterControl(192.168.2.21): string broadcast message was pushed from 1291400 to vehicle 1138272 (slaveControl 1)masterControl(192.168.2.21): vehicle 1333770 was added to slave control 1 

或

log 11:16:08,562 12104 INFO 11:16:08,562 masterControl(192.168.2.21): string broadcast message was pushed from 117772 to vehicle 1217744 (slaveControl 1) 

12104 INFO masterControl（192.168.2.21）：車輛1169775被推到從屬控制1

編輯2：

好像（使用我的客戶機/服務器交換信息RMI連接）如果測井方法是從RMI線程中調用僅出現問題。 ...

編輯3：

我自己解決了這個問題：它看起來像log4j的不完全螺紋保存。在使用單獨的對象同步所有日誌/跟蹤方法後，所有工作都正常。在寫入文件之前，lib可能會將消息寫入線程不安全的緩衝區？

Answer 1

您不需要在記錄器上同步，但在輸出流上同步。

如果使用log4j，輸出應該正確同步。獲得所見即所得的唯一方法是兩個線程同時寫入同一文件。

是否有可能用相同的輸出文件配置了兩個appender？不要那樣做;每個appender必須擁有自己的獨特文件名。

如果你100％確定每個appender寫入不同的文件，唯一剩下的選擇是你有時使用錯誤的記錄器。

Answer 2

難道是不知何故初始化方法被多次調用？每次調用都會添加兩個與現有appender相同文件的新appender。

Answer 3

這個問題是4歲，但我剛剛在2013年遇到了同樣的問題，我想我已經通過爲每個Appender創建一個新的PatternLayout來修復它。希望它可以幫助任何未來有同樣問題的人。