Problème intermittent de fichier verrouillé log4net RollingFileAppender

Nous constatons un problème intermittent sur les machines de développement et de production dans lequel nos fichiers journaux ne sont pas connectés.

Lors de l'exécution en développement et débogage à l'aide de Visual Studio, nous obtenons les messages d'erreur log4net suivants dans la fenêtre de sortie VS:

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

Le processus ne peut pas accéder au fichier «C: \ dossier \ file.log» car il est utilisé par un autre processus.

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 section de configuration devrait ressembler à:

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

Notre solution de contournement actuelle pour le problème consiste à renommer le dernier fichier journal. Nous nous attendrions bien sûr à ce que cela échoue (en raison du verrouillage de fichier susmentionné), mais ce n'est normalement pas le cas. Une ou deux fois, le changement de nom a échoué en raison d'un verrou du processus aspnet_wp.exe .

Notre section de configuration log4net est illustrée ci-dessous:

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

Comme mentionné, nous voyons cela par intermittence sur les machines, mais une fois que le problème survient, il persiste.

Essayez d'ajouter

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

à votre <appender />élément. Il y a un certain impact sur les performances, car cela signifie que log4net verrouille le fichier, y écrit et le déverrouille pour chaque opération d'écriture (par opposition au comportement par défaut, qui acquiert et conserve le verrou pendant une longue période).

Une implication du comportement par défaut est que si vous l'utilisez sous un site Web qui est exécuté sous plusieurs processus de travail s'exécutant sur la même machine, chacun essaiera d'acquérir et de conserver ce verrou indéfiniment, et deux d'entre eux sont va juste perdre. La modification du modèle de verrouillage en verrou minimal permet de contourner ce problème.

(Lors du débogage, des terminaisons sans grâce et de la création de nombreux nouveaux processus de travail sont exactement le type de chose qui est susceptible de se produire.)

Bonne chance!

Soyez également conscient de la FAQ de log4net :

Comment faire pour que plusieurs processus se connectent au même fichier?

Avant même de commencer à essayer l'une des alternatives proposées, demandez-vous si vous avez vraiment besoin de journaliser plusieurs processus dans le même fichier, puis ne le faites pas ;-).

FileAppender propose des modèles de verrouillage enfichables pour ce cas d'utilisation, mais toutes les implémentations existantes présentent des problèmes et des inconvénients.

Par défaut, FileAppender détient un verrou d'écriture exclusif sur le fichier journal pendant la journalisation. Cela empêche les autres processus d'écrire dans le fichier. Ce modèle est connu pour se décomposer avec (au moins sur certaines versions de) Mono sous Linux et les fichiers journaux peuvent être corrompus dès qu'un autre processus tente d'accéder au fichier journal.

MinimalLock n'acquiert le verrou d'écriture que pendant l'écriture d'un journal. Cela permet à plusieurs processus d'entrelacer les écritures dans le même fichier, mais avec une perte considérable de performances.

InterProcessLock ne verrouille pas du tout le fichier mais se synchronise à l'aide d'un Mutex à l'échelle du système. Cela ne fonctionnera que si tous les processus coopèrent (et utilisent le même modèle de verrouillage). L'acquisition et la publication d'un Mutex pour chaque entrée de journal à écrire entraîneront une perte de performances, mais le Mutex est préférable à l'utilisation de MinimalLock.

Si vous utilisez RollingFileAppender, les choses deviennent encore pires car plusieurs processus peuvent essayer de démarrer le fichier journal simultanément. RollingFileAppender ignore complètement le modèle de verrouillage lors du roulement des fichiers, le roulement des fichiers n'est tout simplement pas compatible avec ce scénario.

Une meilleure alternative consiste à enregistrer vos processus dans RemotingAppenders. En utilisant RemoteLoggingServerPlugin (ou IRemoteLoggingSink), un processus peut recevoir tous les événements et les consigner dans un seul fichier journal. L'un des exemples montre comment utiliser RemoteLoggingServerPlugin.

Si tu as

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

et ajouter

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

alors il y aura une erreur pendant le roulement. Le premier processus créera le nouveau fichier et renommera le fichier actuel. Ensuite, le processus suivant fera de même et prendra le fichier nouvellement créé et écrasera le fichier nouvellement renommé. Résultat: le journal du dernier jour est vide.