Log4Net RollingFileAppender spült nicht IO-Puffer mit geringem Volumen Protokoll

Question

Ich bin auf der Suche nach same issue as HENRI COOK did. Soweit wir aus der kurzen Beschreibung entnehmen können, wurde es als bug on Apache Jira gemeldet.

Mein Problem ist im Wesentlichen, dass Ereignisse nur protokolliert werden, wenn die Anwendung heruntergefahren wird (sogar Wochen nach dem Ereignis). Dies geschieht, wenn das Protokollierungsvolumen sehr niedrig ist. Ich sehe das auf einem Windows Server 2008 R2. Dies verhindert, dass wir Produktionsfehler erfassen und darauf reagieren.

Jetzt ist der Appender kein Puffer. Standardmäßig ruft es auch Flush() für den zugrunde liegenden Stream jedes Mal auf, wenn eine Nachricht angehängt wird.

Meine Frage ist, warum spült es nicht? Und gibt es neben programatically flushing all appenders noch Abhilfe? Würden Sie eine pulsing appender eine praktikable Problemumgehung betrachten?

Die appender config:

<appender name="RollingErrorFileAppender" type="log4net.Appender.RollingFileAppender"> 
    <param name="File" value="D:\LogFiles\zzzz\xxxxxx__ERROR" /> 
    <param name="AppendToFile" value="true" /> 
    <param name="DatePattern" value="_yyyyMMddHH&quot;.log&quot;" /> 
    <param name="RollingStyle" value="Date" /> 
    <param name="StaticLogFileName" value="false" /> 
    <filter type="log4net.Filter.LevelRangeFilter"> 
    <param name="LevelMin" value="ERROR" /> 
    <param name="LevelMax" value="FATAL" /> 
    </filter> 
    <layout type="log4net.Layout.PatternLayout"> 
    <param name="ConversionPattern" value="%utcdate{yyyy-MM-dd HH:mm:ss.fff},[%thread],%level,%logger,%m%n"/> 
    </layout> 
</appender> 

UPDATE 2013-06-19

ich nicht in der Lage, das Verhalten mit einem beliebigen Code zu reproduzieren. Egal, wie schlecht ich es versuche, die Daten werden immer sofort auf die Festplatte geschrieben. Es wurde jedoch eine wichtige Beobachtung gemacht: Wenn das erste Schreiben in eine Datei größer als 1 KB ist, wird die modifizierte Zeit niemals mit nachfolgenden Schreibvorgängen aktualisiert. Es wird nur aktualisiert, wenn die Datei mit dem Zeitpunkt der Schließung geschlossen wird. Wenn auf der anderen Seite der erste Schreibvorgang ein kurzer Einzeiler ist, wird jeder nachfolgende Schreibvorgang die Modifizierungszeit aktualisieren. Dieses Verhalten ist zwischen log4net und manuellem IO-Betrieb zwischen 32-Bit-WinXP und 64-Bit-W2k8R2 zwischen .NET 2.0, 3.5 und .NET 4.0 konsistent. Das löst das Problem immer noch nicht, aber zumindest kann ich das seltsame Modifikationszeitmuster jetzt verstehen.

Danke, Rob

Answer 1

Da Sie nur mit Fehlerebene oder schlechten Protokollereignissen sind, und dass der Verkehr ist zum Glück selten, würde ich vorschlagen, Ihre appender Konfiguration sofort bündig.

<param name="ImmediateFlush" value="true" /> 

Dies erspart Ihnen, programmatisch Ihre appender auf jedem Protokollereignis zu spülen (die ohnehin nicht aus dem Klang es funktionierte). Wenn Sie nun Ihren Appender auf mehrere Log-Level aufstocken möchten, könnten natürlich sofort alle Ereignisse ausgelöscht werden.

EDIT

Ich habe die Config-Datei und ein einfaches Hauptprogramm I zum Testen verwendet. Wenn ich Folgendes benutze, werden Log-Ereignisse sofort gelöscht. In Bezug auf Ihren Kommentar kann ich auch die ImmediateFlush Zeile aus dem XML entfernen und den Standardwert true Wert für das Löschen sehen. Ich habe die Zeile in meinem Beispiel beibehalten, um das gewünschte Verhalten explizit anzugeben.

Grund Haupt-Prog:

class Program 
{ 
    static void Main(string[] args) 
    { 
     ILog log = LogManager.GetLogger(typeof(Program)); 
     XmlConfigurator.Configure(new FileInfo(@"C:\temp\logTest.config")); 

     string msg; 
     while ((msg = Console.ReadLine()) != "Done") 
     { 
      log.Error(msg); 
     } 

     LogManager.Shutdown(); 
    } 
} 

logTest.config von Haupt prog verwiesen:

<log4net> 
    <appender name="RollingErrorFileAppender" type="log4net.Appender.RollingFileAppender"> 
     <param name="File" value="C:\temp\log" /> 
     <param name="AppendToFile" value="true" /> 
     <param name="DatePattern" value="_yyyyMMddHH&quot;.log&quot;" /> 
     <param name="RollingStyle" value="Date" /> 
     <param name="StaticLogFileName" value="false" /> 
     <param name="ImmediateFlush" value="true" /> 
     <filter type="log4net.Filter.LevelRangeFilter"> 
      <param name="LevelMin" value="ERROR" /> 
      <param name="LevelMax" value="FATAL" /> 
     </filter> 
     <layout type="log4net.Layout.PatternLayout"> 
      <param name="ConversionPattern" value="%utcdate{yyyy-MM-dd HH:mm:ss.fff},[%thread],%level,%logger,%m%n"/> 
     </layout> 
    </appender> 
    <root> 
     <level value="INFO" /> 
     <appender-ref ref="RollingErrorFileAppender" /> 
    </root> 
</log4net>