⛈️ 🚪 🤳🏽 Investigação: o que é maior do que as prioridades de thread no Windows? 🍽️ ✊🏽 ⚱️

Essa investigação, como muitas outras, começou com o fato de eu estar fazendo meu próprio negócio, sem tentar procurar problemas para mim. Desta vez, tudo o que fiz foi abrir a tampa do laptop e tentar fazer login no sistema.

Pelas primeiras vezes, quando isso resultou em um atraso de vinte segundos, eu ignorei o problema, esperando que ele se resolvesse. Nas próximas vezes, pensei na investigação, mas os problemas de desempenho que surgem mesmo antes de você fazer login são mais difíceis de resolver e eu fiquei com preguiça.

Quando notei que estava evitando fechar o laptop porque tinha medo desses atrasos muito frequentes, percebi que era hora de fazer isso com seriedade.

Felizmente, recentemente corrigi o rastreamento do buffer de anel UIforETWtornando-o confiável, iniciei e comecei a aguardar o próximo evento de atraso. Não tive que esperar muito.

Levei várias vezes para obter o rastreamento ETW completamente bem comigo . E como esse território não me era familiar, levou algum tempo para descobrir o que estava acontecendo. Ainda não entendi completamente o problema, mas 90% entenderam os motivos de sua ocorrência. Consegui aprender muito, incluindo alguns novos detalhes sobre o agendador do Windows, e também encontrei uma solução absolutamente eficaz.

O rastreamento ideal que eu gravei ao carregar no Microsoft Windows Performance Analyzer (WPA) se parece com o seguinte:

Eventos padrão, janelas em foco e uso da CPU.Esta

tabela e dois gráficos contêm uma tonelada de informações. A tabela superior ( Eventos genéricos ) mostra as teclas gravadas no UIforETW. Tentei pressionar uma tecla (código de chave virtual 162) uma vez por segundo até que um campo de entrada de senha fosse exibido. Como essas 17 teclas são selecionadas, no gráfico abaixo, são mostradas com linhas azuis verticais para visualização simplificada do tempo de execução de eventos críticos. O eixo x representa o tempo em segundos.

As barras horizontais no gráfico superior ( Janela em foco ) mostram qual processo foi focado durante esse período. Existem seis processos diferentes no total. O período de rastreamento é o curto período de tempo em que o laptop foi fechado.

O gráfico inferior mostra o uso da CPU . As informações são obtidas dos dados de troca de contexto, portanto, devem ser completamente precisas e completas. Nesse rastreamento, um valor de 100% indica o momento em que todos os oito processadores lógicos do meu notebook de oito threads e quatro núcleos foram usados.

Depois de receber os dados de rastreamento, tive que descobrir o que meu laptop faz secretamente quando a tampa é fechada e até o momento em que volto ao sistema.

Tempestade antes da calmaria

Como podemos ver, o laptop no início do rastreamento é relativamente simples, como deveria ser. Então eu fechei a tampa. Isso parece ter causado um pico na atividade da CPU e uma mudança no foco do Windows. A janela no Focus mudou de UIforETW para Idle, depois para csrss, novamente para Idle, para LogonUI e depois para Idle. Quem teria pensado?

Durante esse intervalo, o laptop executou aproximadamente 17 segundos de processamento da CPU de vários tipos. Parte disso é o trabalho necessário para desligar. Parte - são programas (incluindo ferramentas internas do Google) registradas no Agendador de tarefas para a execução de "Quando um usuário bloqueia uma estação de trabalho" - faz sentido. Eu até notei que o trabalho está sendo feito para criar elementos de interface do usuário para efetuar login quando o usuário continuar trabalhando - você precisa estar preparado com antecedência, certo?

17 segundos de CPU - muito tempo para o laptop dormir. Mesmo no meu laptop com quatro núcleos e oito threads, o processo leva mais de quatro segundos. No meu laptop em casa, são necessários mais de 13 segundos de tempo da CPU para adormecer e quase todos eles são usados no código do Windows. O serviço de política de diagnóstico realmente precisa executar algumas SruDbTableSearches antes que o laptop possa descansar?

Eu acho que esse trabalho excessivo ao dormir também é um problema, mas esse não é o problema que estou procurando. Então eu apenas decidi dar as costas para ela.

E só muito mais tarde eu percebi que foi durante esse período que os grãos de destruição do meu inseto foram lançados ...

Dormir

Depois de bloquear o laptop, não há atividade da CPU. Nesse teste em particular, o laptop ficou bloqueado por cerca de 16 segundos.

Despertar convulsivo

A atividade da CPU após a transição para suspensão é incomparável quando ela começou a despertar. Durante esse período, meu laptop sobrecarregado levou cerca de 172 segundos de tempo de CPU (!!!) por 22,6 segundos. Isto é muito trabalho.

Um dos mistérios desse processo é a queda no uso da CPU para quase zero cerca de um segundo após a explosão inicial de atividade. Esse curto período de inatividade parece bastante anormal, dado o caos ao seu redor. Mas acho que esse recurso não está relacionado ao problema, por isso não prestei atenção nele.

Outro mistério é por que tantosprogramas ganham vida após essa breve pausa. É engraçado que o intruso mais sério responsável por 31,6 dos 172 segundos da CPU foi o Windows Performance Analyzer (WPA) - o próprio programa que eu uso para analisar rastreamentos. As três cópias que eu deixei em execução estão trabalhando duro para renderizar minha interface do usuário, mesmo que ainda não esteja visível.

Além disso, ocorrem padrões escuros ao tentar inicializar dispositivos laptop. KeStallExecutionProcessor é um loop de espera, e era estranho ver que essa é a função mais executável de todo o sistema. Um segundo ciclo de espera ímpar é a única maneira de iniciar o equipamento? É realmente necessário gastar 700 ms de tempo de CPU inicializando o mouse e o teclado ? A Microsoft e a Intel devem ignorar a recomendação da Microsoft sobreum máximo de 50 microssegundos ?

Drivers de um ciclo de espera. O i8042prt.sys foi escrito pela Microsoft. Os dois a seguir são criados pela Intel.

Por fim, muitos programas estão sendo executados ativamente durante esse período . A maioria deles parece estar enfrentando o mesmo problema que o WPA - eles estão desesperados para desenhar pixels em uma tela oculta, e isso alude a um bug do Windows. Mas mesmo sem esse bug, o explorer.exe e outros programas buscam ativamente algo para fazer. Mas, no final, embora esse uso excessivo da CPU seja uma parte necessária do problema, não é o problema em si . Então, novamente, parei de prestar atenção nela.

Foco

Ao analisar rastreamentos, é importante descobrir quando ações importantes ocorrem. A principal evidência foram os eventos de entrada, porque parei de clicar no controle depois que o formulário de entrada da senha apareceu. Aqui estão os três últimos pressionamentos de tecla da tecla Control de forma aproximada no gráfico Window in Focus :

Parece que os eventos críticos estão recebendo o foco do LockApp.exe, após o qual o LogonUI.exe fica quase instantaneamente. Presumivelmente, digitei a senha no LogonUI.exe (é conveniente que o rastreamento não interceptasse os eventos do teclado), após o qual o foco mudou brevemente para o explorer e, em seguida, para o UIforETW, a partir do qual iniciei.

Também parece que o LogonUI.exe não pode obter o foco antes do LockApp.exe - esse padrão se repete em todos os rastreamentos que estudei.

Então, depois de mais de mil palavras dedicadas à solução desse enigma, finalmente temos uma pergunta clara que podemos investigar: por que o LockApp.exe fica em foco depois de sair do tempo de inatividade, leva vinte segundos?

Temos uma pergunta? Ótimo, vamos responder

Usando dados de uso da CPU (precisos) obtidos com a troca de conteúdo, descobri rapidamente que, em vinte segundos depois de ativar o LockApp.exe, havia recebido menos de um milissegundo de tempo de CPU e por mais de 14 segundos (de 35,158 a 49,827 s) não funcionou. geralmente:

LockApp não funciona por um longo tempo

A documentação sobre o significado das colunas nas tabelas Uso da CPU (Preciso) está aqui .

Se um processo ou encadeamento não estiver em execução há algum tempo, e você quiser descobrir o motivo, geralmente dicas importantes podem ser encontradas na primeira alternância de contexto após uma longa pausa, ou seja, alternar para 49,827 segundos de rastreamento. Reordenei as colunas para mostrar mais dados dessa opção de contexto:

LockApp está preparado, mas não é executado. Estranho ...

Contagem, igual a 1 significa que examinamos os dados para uma única alternância de contexto.

Tempo desde o último, igual a 38,2 milhões de microssegundos, significa que esse encadeamento não será executado em 38,2 segundos. Isso por si só não é bom nem ruim. Fluxos ociosos economizam energia e, no final, o laptop estava em sonho por algum tempo.

O tempo de troca simplesmente nos diz quando exatamente o segmento se encaixa na CPU - quando o contexto muda para esse segmento.

E agora vamos para a coluna Pronto. Ele nos diz quanto tempo o thread ficou pronto para ser executado, mas não foi executado. Em outras palavras, esse segmento estava esperando por algo (travar, manipular) e isso é algofoi liberado ou iniciado, mas o encadeamento ainda não foi executado por 19,493 segundos.

Para entender melhor a coluna Pronto (nos) , você pode dar uma olhada na coluna Pronto (s) . Ele nos diz quando o fluxo está preparado. Vemos que, durante 30.333 segundos de rastreamento, esse encadeamento foi preparado para execução, mas não foi executado até 49.827 segundos. Isso parece ser importante.

Esse arranjo de colunas nos mostra a mesma opção de contexto:

Nova pilha de

encadeamentos e pilha de encadeamentos prontos Portanto, esse encadeamento (que o New Thread Stack esperava que o NtWaitForWorkViaWorkerFactory mostrasse) foi solicitado a acordar (o processo do sistema chamando KeSetEvent) logo após abrir a tampa do notebook por 30.333 segundos de rastreamento. Mas começou não naquela época (o que seria “bom”), mas depois de 19.494 s, e isso é ruim.

Normalmente, ao conduzir essa análise de expectativas, passo muito tempo descobrindo por que o fluxo está aguardando e o que fez com que ele não estivesse pronto. Mas foi a primeira vez que fiz uma análise das expectativas, na qual isso não era importante, e a pergunta era por que esse thread pronto não é executado.

Casos ...

A maioria das pessoas não gasta muito tempo estudando traços ETW, portanto, é necessária uma explicação aqui. Isso é muito estranho. Se o encadeamento estiver pronto, ele geralmente inicia instantaneamente ou após alguns milissegundos. A disponibilidade do fluxo, como o nome indica , significa que o fluxo está pronto para execução e quase nada pode interferir nele. Mas vamos descobrir o que pode impedir a execução de um encadeamento concluído.

Linha prioritária

No começo, sugeri que este é um caso simples de "fome" da CPU. Dezenas de processos exigem tempo de CPU e, por isso, o LockApp não obtém o caminho certo até que a carga diminua. No entanto, essa teoria não corresponde exatamente aos sintomas, porque o processo LockApp pode demorar cerca de 18 segundos, mesmo sem o tempo de CPU.

A teoria da fome da CPU é boa porque é verificável. Consegui aumentar a prioridade do processo LockApp usando o Gerenciador de Tarefas (durante um dos breves períodos em que não foi suspenso pelo sistema UWP); portanto, no rastreio final que usei para este post, o LockApp foi executado com alta prioridade. Um encadeamento regular do Windows é executado com uma prioridade de 8 a 10. A prioridade mais alta com a qual um encadeamento regular do Windows (não em tempo real) pode ser executado é 15. Meus rastreamentos de ETW mostraram que o LockApp sempre trabalhava com a prioridade 13 ou superior.

Aqui está uma linha do tempo da CPU para 19.494 segundos críticos, agrupados e coloridos pela prioridade do segmento ( Novo no Pri, a prioridade atual que foi atribuída ao encadeamento). Vemos que os threads com prioridades 4, 8, 9 e 10 consomem a grande maioria do tempo da CPU, especialmente no final:

Usando CPU por prioridade

Aqui está outra imagem com threads ocultos com prioridades de 0 a 12. Cada vez que o gráfico cai abaixo de 12,5% (o que significa um processador lógico do tempo de CPU do meu notebook de oito threads), o LockApp deve ser iniciado e torna-se absolutamente inacreditável que a prioridade impeça a execução com tanta frequência quando muitos threads com prioridade menor ou igual consiga uma tonelada de tempo.

Uso prioritário da CPU, apenas threads de alta prioridade

Eliminar inversão de prioridade

Especula-se que os algoritmos de inversão de prioridade do Windows sejam tão propícios a outros threads que o LockApp.exe seja bloqueado. Mas como os gráficos mostrados acima demonstram que verdadeiras prioridades são usadas nas decisões de planejamento, essa suposição (sempre não convincente) terá que ser abandonada.

Descarga do núcleo da pilha

Quando falei sobre esse quebra-cabeça no Twitter, um dos comentaristas sugeriu que a pilha do núcleo do thread estava descarregada . Eu não estava familiarizado com essa situação, mas após as explicações de John Werth (ele entende em seu campo), desliguei a troca da pilha do kernel e reiniciei o computador. Nada mudou. De fato, não achei que isso ajudaria, pois tenho 32 GB de memória e o problema ocorre repetidamente e com frequência; mas era melhor ter certeza disso.

Pausar processo

Como o LockApp é um aplicativo UWP moderno, está sujeito a restrições semelhantes às dos aplicativos para smartphones. Entre outras coisas, isso significa que ele pode ser suspenso quando não estiver em primeiro plano e, em seguida, "descongelar" quando retornado ao primeiro plano. James Forshaw propôs a gravação do ETW Microsoft-Windows-Kernel-Process para obter dados sobre isso.

Os eventos são projetados para causar confusão máxima. O nome da tarefa Process Freeze é usado para “degelo” e “congelamento”, e a versão do evento win: Stop significa que o processo está sendo iniciado (parou de congelar) e a versão do win: Startsignifica que o processo para (começa a congelar). Tudo isso é extremamente lógico, mas muito confuso. Se os nomes dos eventos fossem divididos em Congelar e Descongelar, haveria menos confusão.

Não há documentação para esses eventos, mas, graças à análise, determinei que esses eventos são sempre criados pelo Serviço de Infraestrutura de Tarefas em Segundo Plano / Broker . O nome e o ID do processo correspondente são indicados no campo FrozenProcessID.

Eventos ProcessFreeze (também usado para degelo) Foi

interessante investigar esse provedor - ele tem muitos eventos promissores - mas, no final, descobriu-se que o LockApp não parou ou descongelou durante o rastreamento. No entanto, esse provedor parecia bastante útil, então eu modifiquei o UIforETW para que as versões futuras sempre o anotassem .

Já descartamos tudo

Nenhuma das teorias descritas acima me pareceu muito provável, e agora todas as excluímos. Comecei a procurar ajuda e pedi que me desse idéias de um amigo da Microsoft. E, naquele momento, descobri que a prioridade de fluxo de 0 a 31, tão conhecida no Windows, na verdade é apenas cinco bits de baixa prioridade de um sistema de prioridade total .

Uso da posição oficial

Aconteceu que minha ignorância foi minha própria culpa. Se eu ler atentamente todas as 108 páginas da seção Threads do Windows Internals, 7ª Edição, Parte 1 , entenderia o que estava acontecendo. Se você quiser avançar, esse tópico será revelado nas páginas 287 a 295 .

Esse campo de super prioridade que eu não conhecia se chama Rank . Ele aparece no WPA como uma coluna oculta padrão (para encontrá-lo, você precisa abrir o View Editor) chamado NewThreadRank . Ao planejar encadeamentos, a Classificação do Encadeamento tem prioridade sobre a prioridade. Quase todos os fluxos têm classificação 0, e um fluxo com classificação 0 sempre tem uma prioridade mais alta do que um fluxo com classificação 2. Incluindo uma colunaNewThreadRank e olhando para o lado esquerdo da tabela, podemos ver imediatamente o problema:

A classificação é mais importante que a prioridade.Os

fluxos do LockApp.exe possuem a Classificação 2, o que significa que, apesar da prioridade 14, eles têm a menor prioridade no sistema.

Uma explicação quase completa

Desde que os threads do LockApp.exe possuem o Rank 2, eles só podem ser executados quando nenhum dos threads do Rank 0 "desejar" executar. Como muitos aplicativos (por razões desconhecidas) ativamente renderizam suas telas invisíveis, eles lutam por cada migalha de tempo da CPU, não deixando nada para classificações mais altas. Depois que o LockApp.exe recebe uma pequena fração do tempo da CPU, ele passa rapidamente para o Rank 0 (e a carga da CPU cai), após o que o processo de login é realizado da maneira usual.

Tendo aprendido essas informações, comecei a estudar como a classificação do LockApp muda com o tempo. Nos últimos segundos antes de dormir, o LockApp mudou repentinamente da classificação 0 para 2. A classificação foi projetada para impedir que a CPU ocupe muito tempo, como quando o Windows Photos está muito interessado no processamento indesejado de segundo plano e faz a transição do rank 2 ao 19:

Microsoft.Photos diminui a classificação

Na documentação, você pode entender que o principal objetivo da classificação do fluxo é o compartilhamento justo do tempo da CPU entre as sessões na máquina, para que os processos de um usuário não prejudiquem outros. Ambas as opções para usar a classificação deixam claro que a classificação do fluxo deve aumentar apenas se consumir muito tempo da CPU e, quando o laptop entrou no modo de espera, o LockApp.exe usou apenas 79,3 ms do tempo da CPU e o restante do sistema - 17 a partir do tempo da CPU . No entanto, o sistema operacional, por algum motivo, decidiu fazer o downgrade do LockApp para 2 no processo de suspensão.

O SO altera a classificação do fluxo apenas se pertencer ao "grupo de planejamento" ( KSCHEDULING_GROUP) e a maioria dos threads em uma instalação típica do Windows não são membros. Consequentemente, a maioria dos encadeamentos não está sujeita a alterações na classificação, portanto, eles podem gastar o tempo da CPU da maneira que desejam.

Puzzles restantes

Infelizmente, ainda não está claro por que o LockApp.exe cai para o Rank 2. antes de ativar o modo de suspensão.Eu assumirei que o LockApp está no grupo de planejamento e provavelmente um dos algoritmos se comporta incorretamente. Mas não consegui encontrar uma API para investigar isso, e o tempo estava se esgotando. Se você conhece algum detalhe, escreva nos comentários do artigo original. O próprio princípio de usar a classificação como o componente mais importante nas decisões de planejamento deve, parece-me, quebrar-se inevitavelmente se a maioria dos processos no sistema não estiver envolvida nele - os segmentos nos grupos de planejamento sempre correm o risco de ficar sem os recursos necessários. O DFSS ( Planejamento de Alocação de Recursos Dinâmicos ) está fadado a falhar se a maioria dos encadeamentos não estiver envolvida.

Além disso, não sei por que tantos aplicativos permanecem ativos depois de dormir. Isso geralmente é explicado pelo fato de que "muitos temporizadores terminam quando o laptop está no modo de suspensão por várias horas", mas essa explicação não é adequada se o laptop estiver em um sonho por apenas alguns segundos, e o comportamento de renderização WPA indicar que algo acontece no sistema de janelas algo errado. Acrescente a isso aplicativos de mau comportamento e drivers de ciclo de espera, e tudo é empilhado ao longo do tempo pela CPU.

O fato de as tempestades de CPU diminuírem e o LockApp iniciar ao mesmo tempo leva a uma explicação óbvia: o LockApp só pode funcionar quando a demanda da CPU diminui. Mas há uma explicação igualmente convincente: assim que o LockApp obtém a capacidade de executar (ou, possivelmente, o LogonUI obtém), a demanda da CPU diminui. Ambas as explicações funcionam, mas acho que a segunda é mais plausível, porque, caso contrário, não podemos explicar por que a renderização aparentemente interminável do WPA para de repente.

Solução para o problema

Assim que percebi que o LockApp.exe é um aplicativo separado que tem problemas de inicialização e que aumentar sua prioridade não ajuda, eu o desativei. O arquivo DisableLockScreen.reg me ajudou com isso:

Windows Registry Editor Version 5.00
[HKEY_LOCAL_MACHINE\SOFTWARE\Policies\Microsoft\Windows\Personalization]
“NoLockScreen”=dword:00000001

Ao desligar a tela de bloqueio, o laptop acorda imediatamente após abrir a tampa. Não notei freadas ou tempestades da CPU e agora é preciso um passo a menos para entrar.

A primeira postagem do twitter que publiquei quando encontrei o problema contém uma linha do tempo para uma investigação que pode ser útil para alguém. Além disso, muitas pessoas inteligentes do twitter chegaram ao post, graças a elas.

Quando voltei ao artigo, descobri que, depois de ligar novamente a tela de bloqueio, o problema desapareceu. Uma reinicialização simples não foi corrigida - em fevereiro, reiniciei várias vezes, mas provavelmente não saberemos por que ela foi perdida.

Investigação: o que é maior do que as prioridades de thread no Windows?