Caçando e analisando o alto uso da CPU em aplicativos .NET

O desenvolvimento de software pode ser um processo muito complicado. Nós, como desenvolvedores, precisamos levar em consideração muitas variáveis ​​diferentes. Alguns não estão sob nosso controle, alguns são desconhecidos para nós no momento da execução real do código e alguns são controlados diretamente por nós. E os desenvolvedores .NET não são exceção a isso.

Diante dessa realidade, as coisas costumam sair conforme o planejado quando trabalhamos em ambientes controlados. Um exemplo é nossa máquina de desenvolvimento, ou um ambiente de integração ao qual temos acesso total. Nestas situações, temos à nossa disposição ferramentas para analisar diferentes variáveis ​​que estão afetando nosso código e software. Nesses casos, também não temos que lidar com cargas pesadas do servidor ou usuários simultâneos tentando fazer a mesma coisa ao mesmo tempo.

Em situações descritas e seguras, nosso código funcionará bem, mas em produção sob carga pesada ou alguns outros fatores externos, podem ocorrer problemas inesperados. O desempenho do software em produção é difícil de analisar. Na maioria das vezes temos que lidar com potenciais problemas em um cenário teórico: sabemos que um problema pode acontecer, mas não podemos testá-lo. É por isso que precisamos basear nosso desenvolvimento nas melhores práticas e documentação para a linguagem que estamos usando e evitar erros comuns.

Como mencionado, quando o software é lançado, as coisas podem dar errado e o código pode começar a ser executado de uma maneira que não planejamos. Podemos acabar na situação em que temos que lidar com problemas sem a capacidade de depurar ou saber com certeza o que está acontecendo. O que podemos fazer neste caso?

Neste artigo, vamos analisar um cenário de caso real de alto uso de CPU de uma aplicação web .NET no servidor baseado em Windows, processos envolvidos para identificar o problema e, mais importante, por que esse problema aconteceu em primeiro lugar e como resolvê-lo.

Uso de CPU e consumo de memória são tópicos amplamente discutidos. Normalmente é muito difícil saber com certeza qual é a quantidade certa de recursos (CPU, RAM, E/S) que um processo específico deve usar e por qual período de tempo. Embora uma coisa seja certa - se um processo estiver usando mais de 90% da CPU por um longo período de tempo, estamos com problemas apenas pelo fato de que o servidor não poderá processar nenhuma outra solicitação nesta circunstância.

Isso significa que há um problema com o próprio processo? Não necessariamente. Pode ser que o processo precise de mais poder de processamento ou esteja lidando com muitos dados. Para começar, a única coisa que podemos fazer é tentar identificar por que isso está acontecendo.

Todos os sistemas operacionais têm várias ferramentas diferentes para monitorar o que está acontecendo em um servidor. Servidores Windows possuem especificamente o gerenciador de tarefas, Performance Monitor, ou no nosso caso usamos New Relic Servers que é uma ótima ferramenta para monitorar servidores.

Primeiros Sintomas e Análise de Problemas

Depois que implantamos nosso aplicativo, durante um lapso de tempo das primeiras duas semanas, começamos a ver que o servidor apresentava picos de uso de CPU, o que fazia com que o servidor não respondesse. Tivemos que reiniciá-lo para disponibilizá-lo novamente, e esse evento aconteceu três vezes durante esse período. Como mencionei antes, usamos New Relic Servers como monitor de servidor, e isso mostrou que o processo w3wp.exe estava usando 94% da CPU no momento em que o servidor travou.

Um processo de trabalho do Internet Information Services (IIS) é um processo do Windows ( w3wp.exe ) que executa aplicativos Web e é responsável por lidar com solicitações enviadas a um servidor Web para um pool de aplicativos específico. O servidor IIS pode ter vários pools de aplicativos (e vários processos w3wp.exe diferentes) que podem estar gerando o problema. Com base no usuário que o processo tinha (isso foi mostrado nos relatórios da New Relic), identificamos que o problema era nosso aplicativo legado de formulário web .NET C#.

O .NET Framework é totalmente integrado às ferramentas de depuração do Windows, então a primeira coisa que tentamos fazer foi examinar o visualizador de eventos e os arquivos de log do aplicativo para encontrar algumas informações úteis sobre o que estava acontecendo. Se tivéssemos algumas exceções registradas no visualizador de eventos, elas não forneceram dados suficientes para analisar. Por isso decidimos dar um passo adiante e coletar mais dados, para que quando o evento surgisse novamente, estivéssemos preparados.

Coleção de dados

A maneira mais fácil de coletar dumps de processo no modo de usuário é com Debug Diagnostic Tools v2.0 ou simplesmente DebugDiag. DebugDiag tem um conjunto de ferramentas para coletar dados (DebugDiag Collection) e analisar dados (DebugDiag Analysis).

Então, vamos começar a definir regras para coletar dados com as Ferramentas de diagnóstico de depuração:

1. Abra a Coleção DebugDiag e selecione Performance .

2. Selecione Performance Counters e clique em Next .
3. Clique Add Perf Triggers de desempenho.
4. Expanda o objeto Processor (não o Process ) e selecione % Processor Time . Observe que, se você estiver no Windows Server 2008 R2 e tiver mais de 64 processadores, escolha o objeto Processor Information em vez do objeto Processor .
5. Na lista de instâncias, selecione _Total .
6. Clique em Add e, em seguida, clique em OK .

7. Selecione o acionador recém-adicionado e clique em Edit Thresholds .

8. Selecione Above no menu suspenso.
9. Altere o limite para 80 .

10. Digite 20 para o número de segundos. Você pode ajustar esse valor se necessário, mas tome cuidado para não especificar um pequeno número de segundos para evitar disparos falsos.

11. Clique OK .
12. Clique Next .
13. Clique Add Dump Target .
14. Selecione Web Application Pool na lista suspensa.
15. Selecione seu pool de aplicativos na lista de pools de aplicativos.
16. Clique OK .
17. Clique Next .
18. Clique Next novamente.
19. Digite um nome para sua regra, se desejar, e anote o local onde os despejos serão salvos. Você pode alterar este local, se desejar.
20. Clique Next .
21. Selecione Activate the Rule Now e clique em Finish .

A regra descrita criará um conjunto de arquivos de minidespejo que serão bastante pequenos em tamanho. O dump final será um dump com memória cheia e esses dumps serão muito maiores. Agora, só precisamos esperar o evento de alta CPU acontecer novamente.

Assim que tivermos os arquivos de despejo na pasta selecionada, usaremos a ferramenta DebugDiag Analysis para analisar os dados coletados:

1. Selecione Analisadores de Desempenho.

2. Adicione os arquivos de despejo.

3. Iniciar Análise.

DebugDiag levará alguns (ou vários) minutos para analisar os despejos e fornecer uma análise. Quando terminar a análise, você verá uma página da web com um resumo e muitas informações sobre os tópicos, semelhante à seguinte:

Como você pode ver no resumo, há um aviso que diz “O alto uso da CPU entre arquivos de despejo foi detectado em um ou mais threads”. Se clicarmos na recomendação, começaremos a entender onde está o problema com nosso aplicativo. Nosso relatório de exemplo se parece com isso:

Como podemos ver no relatório, há um padrão em relação ao uso da CPU. Todos os threads que possuem alto uso de CPU estão relacionados à mesma classe. Antes de pular para o código, vamos dar uma olhada no primeiro.

Este é o detalhe para o primeiro tópico com o nosso problema. A parte que nos interessa é a seguinte:

Aqui temos uma chamada ao nosso código GameHub.OnDisconnected() que acionou a operação problemática, mas antes dessa chamada temos duas chamadas ao Dicionário, que podem dar uma ideia do que está acontecendo. Vamos dar uma olhada no código .NET para ver o que esse método está fazendo:

 public override Task OnDisconnected() { try { var userId = GetUserId(); string connId; if (onlineSessions.TryGetValue(userId, out connId)) onlineSessions.Remove(userId); } catch (Exception) { // ignored } return base.OnDisconnected(); }

Obviamente temos um problema aqui. A pilha de chamadas dos relatórios dizia que o problema era com um dicionário, e neste código estamos acessando um dicionário, e especificamente a linha que está causando o problema é esta:

 if (onlineSessions.TryGetValue(userId, out connId))

Esta é a declaração do dicionário:

 static Dictionary<int, string> onlineSessions = new Dictionary<int, string>();

Qual é o problema com este código .NET?

Todo mundo que tem experiência em programação orientada a objetos sabe que variáveis ​​estáticas serão compartilhadas por todas as instâncias desta classe. Vamos dar uma olhada mais profunda no que estático significa no mundo .NET.

De acordo com a especificação .NET C#:

Use o modificador static para declarar um membro estático, que pertence ao próprio tipo e não a um objeto específico.

Isto é o que as especificações de linguagem do .NET C# dizem sobre classes e membros estáticos:

Como é o caso de todos os tipos de classe, as informações de tipo para uma classe estática são carregadas pelo CLR (Common Language Runtime) do .NET Framework quando o programa que faz referência à classe é carregado. O programa não pode especificar exatamente quando a classe é carregada. No entanto, é garantido que ele seja carregado e tenha seus campos inicializados e seu construtor estático chamado antes que a classe seja referenciada pela primeira vez em seu programa. Um construtor estático é chamado apenas uma vez e uma classe estática permanece na memória durante o tempo de vida do domínio do aplicativo no qual seu programa reside.

Uma classe não estática pode conter métodos, campos, propriedades ou eventos estáticos. O membro estático pode ser chamado em uma classe mesmo quando nenhuma instância da classe foi criada. O membro estático é sempre acessado pelo nome da classe, não pelo nome da instância. Existe apenas uma cópia de um membro estático, independentemente de quantas instâncias da classe são criadas. Métodos e propriedades estáticos não podem acessar campos e eventos não estáticos em seu tipo de conteúdo e não podem acessar uma variável de instância de qualquer objeto, a menos que seja explicitamente passado em um parâmetro de método.

Isso significa que os membros estáticos pertencem ao próprio tipo, não ao objeto. Eles também são carregados no domínio do aplicativo pelo CLR, portanto, os membros estáticos pertencem ao processo que está hospedando o aplicativo e não a threads específicos.

Dado o fato de que um ambiente da Web é um ambiente multithread, porque cada solicitação é um novo thread gerado pelo processo w3wp.exe ; e dado que os membros estáticos fazem parte do processo, podemos ter um cenário em que várias threads diferentes tentem acessar os dados de variáveis ​​estáticas (compartilhadas por várias threads), o que pode eventualmente levar a problemas de multithreading.

A documentação do Dicionário em segurança de encadeamento afirma o seguinte:

Um Dictionary<TKey, TValue> pode dar suporte a vários leitores simultaneamente, desde que a coleção não seja modificada. Mesmo assim, enumerar por meio de uma coleção não é intrinsecamente um procedimento thread-safe. Nos raros casos em que uma enumeração disputa acessos de gravação, a coleção deve ser bloqueada durante toda a enumeração. Para permitir que a coleção seja acessada por vários threads para leitura e gravação, você deve implementar sua própria sincronização.

Esta declaração explica por que podemos ter esse problema. Com base nas informações de dumps, o problema estava no método FindEntry do dicionário:

Se olharmos para a implementação do dicionário FindEntry, podemos ver que o método itera pela estrutura interna (buckets) para encontrar o valor.

Portanto, o código .NET a seguir está enumerando a coleção, que não é uma operação thread-safe.

 public override Task OnDisconnected() { try { var userId = GetUserId(); string connId; if (onlineSessions.TryGetValue(userId, out connId)) onlineSessions.Remove(userId); } catch (Exception) { // ignored } return base.OnDisconnected(); }

Conclusão

Como vimos nos dumps, existem várias threads tentando iterar e modificar um recurso compartilhado (dicionário estático) ao mesmo tempo, o que acabou fazendo com que a iteração entrasse em um loop infinito, fazendo com que a thread consumisse mais de 90% da CPU .

Existem várias soluções possíveis para este problema. O que implementamos primeiro foi bloquear e sincronizar o acesso ao dicionário ao custo de perda de desempenho. O servidor estava travando todos os dias naquele momento, então precisávamos consertar isso o mais rápido possível. Mesmo que essa não fosse a solução ideal, ela resolveu o problema.

O próximo passo para resolver esse problema seria analisar o código e encontrar a solução ideal para isso. Refatorar o código é uma opção: a nova classe ConcurrentDictionary pode resolver esse problema porque ela trava apenas em um nível de bucket, o que melhorará o desempenho geral. Embora, este seja um grande passo, e uma análise mais aprofundada seria necessária.