Sporadyczny problem z zablokowanym plikiem Log4net RollingFileAppender

Widzimy sporadyczny problem na maszynach programistycznych i produkcyjnych, w wyniku którego nasze pliki dziennika nie są rejestrowane.

Podczas uruchamiania w programowaniu i debugowaniu przy użyciu programu Visual Studio otrzymujemy następujące komunikaty o błędach log4net w oknie wyjściowym VS:

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

Proces nie może uzyskać dostępu do pliku „C: \ folder \ plik.log”, ponieważ jest on używany przez inny proces.

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.

Sekcja konfiguracji powinna wyglądać następująco:

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

Obecnie naszym rozwiązaniem tego problemu jest zmiana nazwy ostatniego pliku dziennika. Oczywiście spodziewalibyśmy się, że to się nie powiedzie (z powodu wspomnianej blokady plików), ale zwykle tak się nie dzieje. Raz lub dwa razy zmiana nazwy nie powiodła się z powodu blokady z procesu aspnet_wp.exe .

Nasza sekcja konfiguracji log4net jest pokazana poniżej:

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

Jak wspomniano, widzimy to sporadycznie na komputerach, ale gdy problem się pojawi, będzie nadal występował.

Spróbuj dodać

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

do swojego <appender />żywiołu. Istnieje pewien wpływ na wydajność, ponieważ oznacza to, że log4net zablokuje plik, zapisze do niego i odblokuje go dla każdej operacji zapisu (w przeciwieństwie do domyślnego zachowania, które uzyskuje i utrzymuje blokadę przez długi czas).

Jedną z konsekwencji domyślnego zachowania jest to, że jeśli używasz go w witrynie sieci Web, która jest wykonywana w ramach wielu procesów roboczych działających na tej samej maszynie, każdy z nich będzie próbował uzyskać i utrzymać tę blokadę w nieskończoność, a dwa z nich są po prostu przegra. Zmiana modelu blokowania na minimalną blokadę pozwala obejść ten problem.

(Podczas debugowania niezręczne zakończenia i uruchamianie wielu nowych procesów roboczych są dokładnie tym, co może się wydarzyć).

Powodzenia!

Należy również pamiętać o często zadawanych pytaniach dotyczących log4net :

Jak uzyskać wiele procesów logowania do tego samego pliku?

Zanim zaczniesz wypróbowywać którąkolwiek z dostępnych alternatyw, zadaj sobie pytanie, czy naprawdę potrzebujesz, aby wiele procesów logowało się do tego samego pliku, a następnie nie rób tego ;-).

FileAppender oferuje wtykowe modele blokowania dla tego przypadku, ale wszystkie istniejące implementacje mają problemy i wady.

Domyślnie FileAppender utrzymuje wyłączną blokadę zapisu w pliku dziennika podczas rejestrowania. Zapobiega to zapisywaniu do pliku przez inne procesy. Ten model jest znany z awarii (przynajmniej w niektórych wersjach) Mono w systemie Linux, a pliki dziennika mogą zostać uszkodzone, gdy tylko inny proces spróbuje uzyskać dostęp do pliku dziennika.

MinimalLock uzyskuje blokadę zapisu tylko podczas zapisywania dziennika. Pozwala to wielu procesom na przeplatanie zapisów do tego samego pliku, aczkolwiek ze znaczną utratą wydajności.

InterProcessLock w ogóle nie blokuje pliku, ale synchronizuje się przy użyciu systemu Mutex. Działa to tylko wtedy, gdy wszystkie procesy współpracują (i używają tego samego modelu blokowania). Nabycie i zwolnienie Mutexa dla każdego wpisu dziennika, który ma zostać zapisany, spowoduje utratę wydajności, ale Mutex jest lepszy niż użycie MinimalLock.

Jeśli używasz RollingFileAppender, sytuacja staje się jeszcze gorsza, ponieważ kilka procesów może próbować jednocześnie rozpocząć zwijanie pliku dziennika. RollingFileAppender całkowicie ignoruje model blokowania podczas toczenia plików, pliki toczone po prostu nie są zgodne z tym scenariuszem.

Lepszą alternatywą jest rejestrowanie procesów w RemotingAppenders. Za pomocą RemoteLoggingServerPlugin (lub IRemoteLoggingSink) proces może odbierać wszystkie zdarzenia i rejestrować je w jednym pliku dziennika. Jeden z przykładów pokazuje, jak używać RemoteLoggingServerPlugin.

Jeśli masz

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

i dodaj

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

wtedy wystąpi błąd podczas przewijania. Pierwszy proces utworzy nowy plik i zmieni nazwę bieżącego pliku. Następnie następny proces zrobi to samo i weźmie nowo utworzony plik i nadpisze nowo zmienioną nazwę. W rezultacie logfiel z ostatniego dnia jest pusty.