Problema de arquivo bloqueado intermitente de log4net RollingFileAppender

113

Estamos vendo um problema intermitente nas máquinas de desenvolvimento e produção em que nossos arquivos de log não são registrados.

Ao executar em desenvolvimento e depuração usando Visual Studio, obtemos as seguintes mensagens de erro log4net na janela de saída do VS:

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

O processo não pode acessar o arquivo 'C: \ folder \ file.log' porque ele está sendo usado por outro processo.

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.

A seção de configuração deve ser semelhante a:

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

Nossa solução atual para o problema é renomear o último arquivo de log. É claro que esperamos que isso falhe (devido ao bloqueio de arquivo mencionado anteriormente), mas normalmente não. Uma ou duas vezes a renomeação falhou devido a um bloqueio do processo aspnet_wp.exe .

Nossa seção de configuração log4net é mostrada abaixo:

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

Conforme mencionado, vemos isso intermitentemente nas máquinas, mas quando o problema acontece, ele persiste.

Richard Ev
fonte

Respostas:

172

Tente adicionar

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

ao seu <appender />elemento. Há algum impacto no desempenho porque isso significa que o log4net bloqueará o arquivo, gravará nele e o desbloqueará para cada operação de gravação (em oposição ao comportamento padrão, que adquire e mantém o bloqueio por um longo tempo).

Uma implicação do comportamento padrão é que se você estiver usando em um site que está sendo executado em vários processos de trabalho em execução na mesma máquina, cada um tentará adquirir e manter esse bloqueio indefinidamente, e dois deles estão apenas vou perder. Alterar o modelo de bloqueio para o bloqueio mínimo contorna esse problema.

(Ao depurar, encerramentos deselegantes e acionar muitos novos processos de trabalho é exatamente o tipo de coisa que provavelmente acontecerá.)

Boa sorte!

Nicholas Piasecki
fonte
Me salvou de muito coçar a cabeça porque meu logger estava funcionando intermitentemente. Eu adicionei processos de trabalho ao pool de aplicativos, dã!
RhinoDevX64 de
Estou usando isso em um serviço e além dessa alteração, o usuário do serviço executou conforme precisava de permissão para escrever também. Obrigado!
LowTide
Muito obrigado, economizou muito tempo.
Siva
2
Eu gostaria apenas de ler o arquivo, mas o log4net bloqueia para leitura também ... pode bloquear apenas para gravação e leitura compartilhada
JobaDiniz
37

Também esteja ciente das Perguntas frequentes do log4net :

Como faço para que vários processos façam logon no mesmo arquivo?

Antes mesmo de começar a tentar qualquer uma das alternativas fornecidas, pergunte-se se você realmente precisa ter vários processos logados no mesmo arquivo, então não faça isso ;-).

FileAppender oferece modelos de bloqueio plugáveis ​​para este caso de uso, mas todas as implementações existentes têm problemas e desvantagens.

Por padrão, o FileAppender mantém um bloqueio de gravação exclusivo no arquivo de log enquanto ele está registrando. Isso evita que outros processos gravem no arquivo. Este modelo é conhecido por quebrar (pelo menos em algumas versões do) Mono no Linux e os arquivos de log podem ser corrompidos assim que outro processo tentar acessar o arquivo de log.

MinimalLock adquire o bloqueio de gravação apenas enquanto um log está sendo gravado. Isso permite que vários processos intercalem as gravações no mesmo arquivo, embora com uma perda considerável de desempenho.

InterProcessLock não bloqueia o arquivo, mas sincroniza usando um Mutex de todo o sistema. Isso só funcionará se todos os processos cooperarem (e usarem o mesmo modelo de bloqueio). A aquisição e liberação de um Mutex para cada entrada de log a ser gravada resultará em perda de desempenho, mas o Mutex é preferível ao uso do MinimalLock.

Se você usar RollingFileAppender, as coisas ficarão ainda piores, pois vários processos podem tentar iniciar a rolagem do arquivo de log simultaneamente. RollingFileAppender ignora completamente o modelo de bloqueio durante a rolagem de arquivos; a rolagem de arquivos simplesmente não é compatível com este cenário.

Uma alternativa melhor é fazer com que seus processos sejam registrados em RemotingAppenders. Usando o RemoteLoggingServerPlugin (ou IRemoteLoggingSink), um processo pode receber todos os eventos e registrá-los em um único arquivo de log. Um dos exemplos mostra como usar o RemoteLoggingServerPlugin.

Ciprian Teiosanu
fonte
6

Se você tem

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

e adicione

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

então haverá um erro enquanto a rolagem acontece. O primeiro processo criará o novo arquivo e renomeará o arquivo atual. Então o próximo processo fará o mesmo e pegará o arquivo recém-criado e sobrescreverá o arquivo recém-renomeado. Resultando no logfiel do último dia vazio.

Jonte
fonte
1
Isso é verdadeiro apenas quando vários processos estão acessando o mesmo arquivo contínuo. É seguro dentro do mesmo processo. hectorcorrea.com/blog/log4net-thread-safe-but-not-process-safe
Mike Chamberlain
@MikeChamberlain De acordo com o OP (veja seu comentário à resposta), haverá vários trabalhadores trabalhando simultaneamente, usando log4net para registrar. Portanto, esta questão é pertinente!
seebiscuit