Problema intermitente de archivo bloqueado log4net RollingFileAppender

Estamos viendo un problema intermitente en las máquinas de desarrollo y producción por el cual nuestros archivos de registro no se registran.

Cuando se ejecuta en desarrollo y depuración con Visual Studio, obtenemos los siguientes mensajes de error de log4net en la ventana de salida de VS:

log4net:ERROR [RollingFileAppender] Unable to acquire lock on file C:\folder\file.log.

El proceso no puede acceder al archivo 'C: \ folder \ file.log' porque está siendo utilizado por otro proceso.

log4net:ERROR XmlConfigurator: Failed to find configuration section 'log4net' in the application's .config file.
Check your .config file for the <log4net> and <configSections> elements.

La sección de configuración debería verse así:

<section
  name="log4net"
  type="log4net.Config.Log4NetConfigurationSectionHandler,log4net" />

Nuestra solución actual para el problema es cambiar el nombre del último archivo de registro. Por supuesto, esperaríamos que esto fallara (debido al bloqueo de archivo mencionado anteriormente), pero normalmente no es así. Una o dos veces el cambio de nombre ha fallado debido a un bloqueo del proceso aspnet_wp.exe .

Nuestra sección de configuración de log4net se muestra a continuación:

<log4net>
  <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
    <file value="C:\folder\file.log"/>
    <appendToFile value="true" />
    <datePattern value="yyyyMMdd" />
    <rollingStyle value="Date" />
    <maximumFileSize value="10MB" />
    <maxSizeRollBackups value="100" />
    <layout type="log4net.Layout.PatternLayout">
      <header value="[Header]&#xA;"/>
      <footer value="[Footer]&#xA;"/>
      <conversionPattern value="%date %-5level %logger ${COMPUTERNAME} %property{UserHostAddress} [%property{SessionID}] - %message%newline"/>
    </layout>
  </appender>
  <root>
    <level value="INFO"/>
    <appender-ref ref="RollingLogFileAppender"/>
  </root>
</log4net>

Como se mencionó, estamos viendo esto de manera intermitente en las máquinas, pero una vez que ocurre el problema, persiste.

Intenta agregar

<lockModel type = "log4net.Appender.FileAppender + MinimalLock" />

a tu <appender />elemento. Hay cierto impacto en el rendimiento porque esto significa que log4net bloqueará el archivo, escribirá en él y lo desbloqueará para cada operación de escritura (a diferencia del comportamiento predeterminado, que adquiere y mantiene el bloqueo durante mucho tiempo).

Una implicación del comportamiento predeterminado es que si lo está utilizando en un sitio web que se está ejecutando en varios procesos de trabajo que se ejecutan en la misma máquina, cada uno intentará adquirir y retener ese bloqueo indefinidamente, y dos de ellos son solo voy a perder. Cambiar el modelo de bloqueo al bloqueo mínimo soluciona este problema.

(Al depurar, las terminaciones desagradables y la puesta en marcha de muchos procesos de trabajo nuevos es exactamente el tipo de cosas que probablemente suceda).

¡Buena suerte!

También tenga en cuenta las preguntas frecuentes de log4net :

¿Cómo consigo que varios procesos inicien sesión en el mismo archivo?

Antes incluso de empezar a probar cualquiera de las alternativas proporcionadas, pregúntese si realmente necesita tener varios procesos registrados en el mismo archivo, entonces no lo haga ;-).

FileAppender ofrece modelos de bloqueo conectables para este caso de uso, pero todas las implementaciones existentes tienen problemas e inconvenientes.

De forma predeterminada, FileAppender mantiene un bloqueo de escritura exclusivo en el archivo de registro mientras se está registrando. Esto evita que otros procesos escriban en el archivo. Se sabe que este modelo se descompone con (al menos en algunas versiones de) Mono en Linux y los archivos de registro pueden dañarse tan pronto como otro proceso intente acceder al archivo de registro.

MinimalLock solo adquiere el bloqueo de escritura mientras se escribe un registro. Esto permite que varios procesos intercalen escrituras en el mismo archivo, aunque con una pérdida considerable de rendimiento.

InterProcessLock no bloquea el archivo en absoluto, pero se sincroniza mediante un mutex de todo el sistema. Esto solo funcionará si todos los procesos cooperan (y usan el mismo modelo de bloqueo). La adquisición y liberación de un Mutex para cada entrada de registro que se escriba resultará en una pérdida de rendimiento, pero el Mutex es preferible al uso de MinimalLock.

Si usa RollingFileAppender, las cosas empeoran aún más, ya que varios procesos pueden intentar comenzar a rodar el archivo de registro al mismo tiempo. RollingFileAppender ignora por completo el modelo de bloqueo cuando se mueven archivos; los archivos rodantes simplemente no son compatibles con este escenario.

Una mejor alternativa es tener sus procesos registrados en RemotingAppenders. Con RemoteLoggingServerPlugin (o IRemoteLoggingSink), un proceso puede recibir todos los eventos y registrarlos en un solo archivo de registro. Uno de los ejemplos muestra cómo utilizar RemoteLoggingServerPlugin.

Si usted tiene

<staticLogFileName value="true" />
<rollingStyle value="Date" />
<datePattern value="yyyyMMdd" />

y añadir

<lockingModel type="log4net.Appender.FileAppender+MinimalLock" />

entonces habrá un error mientras ocurre el balanceo. El primer proceso creará el nuevo archivo y cambiará el nombre del archivo actual. Luego, el siguiente proceso hará lo mismo y tomará el archivo recién creado y sobrescribirá el archivo recién renombrado. Dando como resultado que el logfiel del último día esté vacío.