2013-02-19 10 views
14

Sto riflettendo sullo same issue as HENRI COOK did. È stato segnalato come bug on Apache Jira per quanto possiamo dire dalla breve descrizione.Log4Net RollingFileAppender non scarica il buffer IO con il registro del volume basso

Il mio problema in sostanza è che gli eventi vengono registrati solo quando l'applicazione viene chiusa (anche settimane dopo l'evento). Ciò accade quando il volume di registrazione è molto basso. Sto vedendo questo su un Windows Server 2008 R2. Questo ci impedisce di catturare e reagire agli errori di produzione.

Ora l'appender non è un buffer. Per impostazione predefinita, chiama anche Flush() sul flusso sottostante ogni volta che un messaggio viene aggiunto.

La mia domanda è PERCHÉ non si sta scaricando? E c'è qualche rimedio oltre allo programatically flushing all appenders? Prenderesti in considerazione un pulsing appender come soluzione alternativa?

La configurazione appender:

<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

non sono stato in grado di riprodurre il comportamento con qualsiasi codice. Non importa quanto mi sforzi, i dati vengono sempre scritti sul disco immediatamente. Tuttavia, è stata effettuata un'osservazione importante: se la prima scrittura su un file è maggiore di 1KB, la modifica non viene mai aggiornata con le scritture successive. Sarà aggiornato solo quando il file viene chiuso con il tempo di chiusura. Se d'altra parte la prima scrittura è una breve copertina, ogni successiva scrittura aggiornerà il tempo modificato. Questo comportamento è coerente tra log4net e operazione manuale IO, tra WinXP a 32 bit e W2k8R2 a 64 bit, tra .NET 2.0, 3.5 e .NET 4.0. Questo non risolve ancora il problema, ma almeno riesco a capire lo strano schema di modifica-ora.

Grazie, Rob

+0

puoi pubblicare la configurazione per l'appender si sta utilizzando? –

+0

@AdamS, config added, thank you – Rbjz

+0

E per chiarire, non vedi i registri rotolare ogni ora quando c'è stato almeno un livello di ERRORE o un evento di registrazione superiore durante quel periodo?Ho provato con il tuo appender e ho visto i log scorrere e rotolare correttamente. –

risposta

25

Dal momento che sono solo interessati con livello di errore o di eventi di log peggio, e che il traffico è fortunatamente raro, vorrei suggerire la configurazione appender per sciacquare immediatamente.

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

In questo modo si evita di dover svuotare di programmazione il tuo appender su ogni evento di registro (che non funzionava comunque dal suono di esso). Ora, se si desidera aprire l'appender fino a più livelli di registro, ovviamente lo scarico immediato di tutti gli eventi potrebbe avere maggiori problemi di prestazioni.

EDIT

ho aggiunto il file di configurazione e un semplice programma principale che ho usato per il test. Usando quanto segue, vedo gli eventi del registro immediatamente svuotati. Per quanto riguarda il tuo commento, posso anche rimuovere la riga ImmediateFlush dall'XML e vedere il valore predefinito di true per lo svuotamento. Ho mantenuto la linea nel mio esempio allo scopo di dichiarare esplicitamente il comportamento desiderato.

base prog principale:

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 riferimento da prog principale:

<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> 
+1

Grazie a @AdamS, anche se ho il coraggio di non essere d'accordo. Se si dà un'occhiata al codice di 'private bool m_immediateFlush = true;' e 'override protected void Append (LoggingEvent loggingEvent)' in [v1.2.10 TextWriterAppender] (http://svn.apache.org/viewvc/logging/log4net/ tags/log4net-1.2.10/src/Appender/TextWriterAppender.cs? view = markup), sarai d'accordo con me che ImmediateFlush è true di default e quindi l'appender chiama effettivamente Flush() su ogni Append() come ho già detto nella Q. – Rbjz

+1

Modificato la mia risposta con il programma di test che ho usato. Con quello posso vedere gli eventi immediatamente arrossati. Non vedi lo stesso comportamento? –

+0

Grazie AdamS, è una grande idea. Ci proverò domani spero. – Rbjz

Problemi correlati