Serviço .NET Travando Intermitentemente

Uma vez trabalhei em um caso onde um serviço intermitentemente parava de atender as requisições do System.Runtime.Remoting sem gerar nenhum log de erro.

O erro ocorria no ambiente de produção e a primeira ação tomada foi coletar um dump  no momento do travamento.

Existem várias formas e cenários para coletar um dump. Nesse caso específico, o dump pode ser coletado através do gerenciador de tarefas do Windows. Na aba Processos do Gerenciador de Tarefas, localize o processo do serviço e clique em Create a dump file (ou criar arquivo de despejo).

Utilizamos o WinDbg para abrir e analisar o dump. O  WinDbg é um User mode e Kernel mode debugger com uma interface gráfica que usa a infraestrutura dos debuggers NTSD, CDB e KD para prover um ambiente mais parecido com o Visual Studio, com janelas de watch, breakpoints visuais em linhas de código e outras facilidades, por exemplo, exibir variáveis (incluindo objetos C++), stack traces e memória.

Também utilizamos a extensão Psscor2 do WinDbg criada para ajudar no diagnóstico de problemas de alto consumo de memória, alto consumo de processamento, chashes, hangs e outros problemas que podem ocorrer em aplicações do Framework .Net, para as versões 2.0, 3.0 e 3.5.

Comandos Executados

.load psscor2

Esse comando é executado para carregar a extensão de depuração de código gerenciado Psscor2 que é utilizada para ajudar no diagnóstico de problemas em aplicações do Framework .Net, para as versões 2.0, 3.0 e 3.5.

!threads

Esse comando é utilizado para obter as informações de cada thread gerenciada do sistema incluindo a última exceção que foi gerada pela thread. O objetivo da execução desse comando é verificar quais eram as threads que estavam sendo executadas e se haviam exceções geradas pelas threads, conforme exibido a seguir:

Através do resultado acima é possível observar uma quantidade elevada de threads sendo executada (4007) e uma quantidade elevada de threads (4005) aguardando enfileirada.

!eestack –ee

Através desse commando é possível obter o call stack de todas as threads gerenciadas do processo. Ao analisar a pilha dessas threads é possível identificar que a maioria das 4000 threads estavam executando o método  SerializeToDisk da classe RefDataCacheController, conforme exibido a seguir:

  !threadpool

 Esse comando é utilizado para exibir o estado do thread pool durante o momento em que o dump foi coletado. Através desse identificamos que a quantidade de threads utilizadas pela aplicação atingiu o valor máximo do limite disponível no ThreadPool, conforme exibido a seguir:

Além de todas threads do thread pool estarem ocupadas, havia uma fila de 36522 work items para serem executados pelo thread pool. Uma vez  que o remoting utiliza o thread pool para atender as requisições remotas,  o serviço não para de atender as requisições de remoting.

Através da execução dos comandos citados anteriormente foi possível identificar que o processo estava consumindo todas as threads disponíveis no thread pool e que essas threads executavam o método  SerializeToDisk da classe RefDataCacheController.

Ao analisar o código-fonte da aplicação identificamos que esse método é executado a cada segundo através de um Timer (System.Threading.Timer) definido no construtor dessa classe. Nesse método existe um código responsável por desativar o timer visando garantir que apenas uma thread seja executada ao mesmo tempo e que não haja enfileiramento, conforme destacado no fragmento de código a seguir:

O fato da função responsável por desativar o timer ser executado dentro do lock (bloco responsável por garantir que apenas uma thread execute ao mesmo tempo) possibilita que mais de uma thread seja executada simultaneamente quando, por exemplo, houver uma demora na execução das duas funções que são executadas antes desse bloco.  O intervalo de um segundo do timer mais o atraso na execução dessas funções permite que a primeira thread habilite o timer justamente após o momento em que a segunda thread desativa o mesmo.

É importante ressaltar que a classe System.Threading.Timer é thread safe, dessa forma, suas operações não precisam ser sincronizadas podendo ser removida dentro do lock.

A equipe de desenvolvimento foi alertada para rever a periodicidade ao qual o timer deve ser executado e alterar o método SerializeToDisk para que o método responsável por desativar a thread seja o primeiro a ser executado.