Temos dois SQL Server 2016 SP2 CU6 Enterprise em execução em hardware físico (32 núcleos) com um AG que contém 5 db's. O secundário não é legível. Hoje fizemos um failover manual planejado, para que pudéssemos fazer manutenção no outro servidor. Fizemos o failover em um momento em que não havia carga pesada.
O failover foi executado por meio da GUI do SSMS e não apresentou erros. Mas, vários minutos depois, recebemos muitos telefonemas que os usuários não conseguiram fazer login. Nossa primeira tentativa de solucionar o problema foi fazer uma conexão com o SSMS, mas isso deu um erro de que não conseguimos conectar, a mensagem de erro exata que não me lembro.
Em seguida, demos uma olhada no arquivo errorlog no bloco de notas e foi assim que o SQL Server Engine travou. Não houve novas entradas adicionadas ao log após o failover.
Devido à alta urgência do problema, reiniciamos o SQL Server Service no primário e o problema desapareceu.
Poderíamos ter tentado fazer uma conexão DAC para ver qual era o problema, mas o objetivo era colocar o servidor online novamente o mais rápido possível.
Depois que tudo estava novamente online, começamos a analisar os arquivos de log.
No log de erros do primário antigo, encontramos vários erros 35278. Nenhuma transação de longa execução estava sendo executada no momento do failover.
Em seguida foi o arquivo de evento AlwaysON_health, aqui as entradas apenas pararam após o failover.
Em seguida, demos uma olhada no *_*_SQLDIAG_*_*.xelarquivo. Aqui tivemos sorte.
A primeira coisa que notamos foi:
<queryProcessing maxWorkers="960" workersCreated="1064"
workersIdle="23" tasksCompletedWithinInterval="19" pendingTasks="34"
oldestPendingTaskWaitingTime="1316776"
Por algum motivo, o número máximo de trabalhadores foi excedido, isso pode explicar por que ninguém conseguiu se conectar.
Estas foram as tarefas pendentes:
<pendingTasks><br>
<entryPoint name="Process Command" count="14" /><br>
<entryPoint name="SNI New Connection" count="2" /><br>
<entryPoint name="SNI Accept Done" count="3" /><br>
<entryPoint moduleName="sqlmin.dll" imageBase="0x7ff827e80000" size="0x251e000" address="0x7ff8286622e0" count="6" /><br>
<entryPoint moduleName="sqlmin.dll" imageBase="0x7ff827e80000" size="0x251e000" address="0x7ff8292b1190" count="2" /><br>
<entryPoint moduleName="sqldk.dll" imageBase="0x7ff827120000" size="0x4c9000" address="0x7ff827125e60" count="7" /> <br>
</pendingTasks>
Havia também vários processos bloqueados nesse arquivo. Todos eles tinham um waitresource como DATABASE: 5:5, DATABASE: 5:15, DATABASE: 5:26, ...
Todos esses processos tinham lastbatchstartede lastbatchcompletedconfigurados para 1900-01-01. O tempo de espera foi igual a quanto tempo o failover ocorreu.
Em nosso monitoramento vimos que havia um total de 950 processos bloqueados.
Esta é uma amostra de um relatório de processo bloqueado:
<blocked-process-report monitorLoop="0">
<blocked-process>
<process id="process13f08032ca8" taskpriority="0" logused="10000" waitresource="DATABASE: 5:3 " waittime="1334205" schedulerid="4" kpid="11752" status="suspended" spid="95" sbid="0" ecid="0" priority="0" trancount="0" lastbatchstarted="1900-01-01T00:00:00" lastbatchcompleted="1900-01-01T00:00:00" lastattention="1900-01-01T00:00:00" clientapp="our_app" hostname="host2021" hostpid="14196" loginname="user1" isolationlevel="read committed (2)" xactid="0" currentdb="1" currentdbname="master" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
<executionStack />
<inputbuf>
</inputbuf>
</process>
</blocked-process>
<blocking-process>
<process status="suspended" waitresource="DATABASE: 5:3 " waittime="1335893" spid="70" sbid="0" ecid="0" priority="0" trancount="0" lastbatchstarted="1900-01-01T00:00:00" lastbatchcompleted="1900-01-01T00:00:00" lastattention="1900-01-01T00:00:00" clientapp="our_app" hostname="host1" hostpid="1324" loginname="user1" isolationlevel="read committed (2)" xactid="0" currentdb="1" currentdbname="master" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
<executionStack />
<inputbuf>
</inputbuf>
</process>
</blocking-process>
</blocked-process-report>
<blocked-process-report monitorLoop="0">
<blocked-process>
<process id="process13f08033848" taskpriority="0" logused="10000" waitresource="DATABASE: 5:3 " waittime="1335893" schedulerid="4" kpid="12004" status="suspended" spid="70" sbid="0" ecid="0" priority="0" trancount="0" lastbatchstarted="1900-01-01T00:00:00" lastbatchcompleted="1900-01-01T00:00:00" lastattention="1900-01-01T00:00:00" clientapp="our_app" hostname="host1" hostpid="1324" loginname="user1" isolationlevel="read committed (2)" xactid="0" currentdb="1" currentdbname="master" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
<executionStack />
<inputbuf>
</inputbuf>
</process>
</blocked-process>
<blocking-process>
<process status="background" waittime="1139955" spid="141" sbid="0" ecid="0" priority="0" trancount="0">
<executionStack />
<inputbuf>
</inputbuf>
</process>
</blocking-process>
</blocked-process-report>
Um dos processos de bloqueio foi executado como usuário SAe teve o comando UNKNOWN TOKEN. O last_wait_typetempo dessas sessões foi PARALLEL_REDO_WORKER_WAIT_WORKe teve um last_request_start_timetempo igual ao tempo em que fizemos o failover.
Eu não esperava encontrar esse tipo de espera no primário.
É correto dizer que isso PARALLEL_REDO_WORKER_WAIT_WORKnão deveria ser esperado em uma primária?
Também em nosso monitoramento encontramos aproximadamente 1000 sessões que tinham o status SLEEPINGe tinham um last_request_start_timede 01/01/1900.
Isso não parece nada normal.
Alguém pode explicar quais são essas tarefas pendentes?
Meu palpite da causa raiz são as 1000 sessões que tiveram o status SLEEPING, todas usaram um trabalhador. Isso causou as tarefas pendentes e, devido ao processo de bloqueio, nenhum trabalhador pôde fazer nenhum trabalho. Isso fez com que o failover em algum lugar ficasse preso.
Isso pode estar correto?
Como nenhuma investigação ou coleta de dados foi concluída, será difícil dizer exatamente o que estava acontecendo no momento.
Sim, por algum motivo e não temos dados sobre esse motivo :( Parece que o servidor tem 32 processadores, o que deve ser suficiente para lidar com 5 bancos de dados em um grupo de disponibilidade. não sei ou você não está explicando.
Como não conhecemos o contexto do banco de dados para isso, é impossível dizer. Eu direi que, se houver apenas um único grupo de disponibilidade e essa instância for a principal, não, isso não seria esperado. Se, no entanto, houver outros grupos de disponibilidade dos quais não temos conhecimento e isso for secundário, sim, é esperado. Novamente, não temos todas as informações. Isso também pressupõe que não havia fila de redo que precisasse ser drenada em nenhum dos bancos de dados - o que, novamente, não sabemos ou não temos essa informação.
O
Process Commandsestão tentando executar algo em uma conexão. AsSNI*novas conexões estão sendo feitas.Quantas sessões estava bloqueando? O que estava bloqueando? etc. Novamente, falta de informação então não posso dizer se é algo ou não.
De onde eles estavam vindo? O que eles correram pela última vez? Pode ser normal se você tiver uma réplica secundária legível e alguém quiser executar vários relatórios ou consultas. Novamente, preciso de mais informações.
Poderia ser. Obviamente, você ficou sem threads de trabalho, como e por que isso aconteceu é desconhecido, pois simplesmente não há dados suficientes.
Aí está o seu problema subjacente. Parece que
clientapp="our_app"estava conectado (está tudo no master) e estava fazendo algum tipo de consulta ao banco de dados. Parece que o banco de dados ainda não terminou de refazer (daí o tipo de espera) e todas as suas sessões fizeram backup umas das outras.enfrentamos o número máximo de problemas de thread de trabalho em nosso ambiente e o único motivo é o bloqueio. uma vez que você não gravou nenhuma sessão de bloqueio para nos levar a encontrar a causa raiz. Além disso, você pode configurar o alerta de bloqueio do agente sql com latência de envio de > 5 segundos e anexar o trabalho para capturar dados de bloqueio. temos um ambiente altamente oltp e um único bloqueio na tabela principal aumenta o thread de trabalho para atingir 1000 em menos de 1 minuto. aumentamos o thread de trabalho para 5000 para obter tempo suficiente para investigar e eliminar as sessões de bloqueio porque não queremos reiniciar o serviço.
encontramos gatilhos, culpeits de consultas de longa duração que mantêm o bloqueio de tabela na tabela principal usada e aumentam as sessões de bloqueio e, em um certo ponto, o sql não responde. Nesta situação, para tomar a sessão DAC e matar a sessão de bloqueio de cabeça ou reiniciar o serviço sql.
Embora a Microsoft recomende não definir o thread máximo de trabalho devido a vários motivos. Primeiro, configure o alerta de bloqueio e corrija as consultas para evitar esse tipo de problema.