Log4Net performance

Question

He escrito una aplicación C# que se ejecuta constantemente en un bucle y varios hilos escriben en un archivo log4net.

El problema es que cuanto más tiempo se ejecuta la aplicación, más tiempo lleva completar un ciclo. He ejecutado un analizador de rendimiento ANTS, y noté que la mayor parte de este tiempo de CPU se usa para iniciar sesión con log4.net.

Cuanto más detallados sean los registros, más CPU usará y después de 30 minutos usará el 100% de la CPU. Si deshabilito el registro, el tiempo de un bucle permanece constante a lo largo del tiempo. Eché un vistazo al Monitor de rendimiento de Windows y el Disco físico está inactivo la mayor parte del tiempo.

He intentado mantener mi registro al mínimo, pero incluso con cantidades relativamente bajas de registro todavía estoy experimentando el problema.

Aquí es una muestra de mi archivo de configuración Log4net.xml:

<log4net> 
    <root> 
    <!-- Levels: OFF, DEBUG, INFO, WARN, ERROR, FATAL--> 
    <level value="INFO" /> 
    <appender-ref ref="RollingLogFileAppender" /> 
    </root> 

    <!--Logs to a file--> 
    <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender"> 
    <file value="c:\\logs\\log-file.txt" /> 
    <appendToFile value="true" /> 
    <lockingModel type="log4net.Appender.FileAppender+ExclusiveLock" /> 
    <rollingStyle value="Composite" /> 
    <datePattern value="yyyyMMdd" /> 
    <maxSizeRollBackups value="20" /> 
    <maximumFileSize value="1MB" /> 
    <layout type="log4net.Layout.PatternLayout"> 
     <conversionPattern value="%date [%thread] %-5level %logger %L %M Schdl:[%property{scheduleContext}] Job:[%property{jobContext}] - %message%newline" /> 
    </layout> 
    </appender> 
</log4net> 

estoy usando el mismo registrador de cada objeto que registra.

log4net.ILog logger; 
    log4net.Config.BasicConfigurator.Configure(); 
    logger = log4net.LogManager.GetLogger(typeof(myProject)); 

¿Por qué usaría más y más CPU cuanto más tiempo funcione?

Cualquier consejo sobre cómo mejorar esto sería apreciado.

Answer 1

¿Está configurando log4net en cada objeto que se registra? Se ve así desde tu código. La configuración debe hacerse una vez por proceso, p. al inicio y luego sus objetos solo deberían adquirir el registrador.

Para cada clase que necesita para iniciar la sesión normalmente tienen el siguiente patrón:

class SomeClass 
{ 
    private static readonly ILog log = LogManager.GetLogger(typeof(SomeClass)); 
    ... 
} 

El uso de este patrón obtendrá automáticamente madereros que son jerárquica de acuerdo con el espacio de nombres y el nombre de la clase.

Answer 2

(nunca he usado antes, así log4net tomo lo que recomiendo con precaución)

Se puede escribir un proxy asíncrono a Log4net componente e inicie sesión en un hilo dedicado. Ya no estará bloqueando sus hilos principales con intentos de escribir en el archivo de registro.

Esto es inútil si log4net ya tiene un proxy asíncrono.

Answer 3

¿Qué estás haciendo con esas propiedades de contexto? Schdl:[%property{scheduleContext}] Job:[%property{jobContext}] Si asigna algo más que solo un valor aquí (o un objeto con un método simple ToString()), puede empantanar el rendimiento. Consulte el manual de log4net bajo Active Property Values para tener una idea de lo que estoy hablando.

Peter Lillevold tiene una buena sugerencia sobre la configuración de log4net solo una vez. También puede poner la siguiente línea en su AssemblyInfo.archivo cs:

[assembly: log4net.Config.XmlConfigurator()] 

La siguiente línea es fácil de cortar y pegar en cualquier clase que hace la tala:

private static readonly log4net.ILog _log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType); 

También puede intentar encender log4net registro interno para ver lo que está pasando:

<appSettings> 
    <add key="log4net.Internal.Debug" value="true"/> 
</appSettings>