Análise da Distribuição Inadequada de Wrk Latency
API7.ai
September 3, 2018
O wrk é uma excelente ferramenta de teste de estresse HTTP construída sobre os projetos de código aberto Redis, NGINX, Node.js e LuaJIT, aproveitando seus pontos fortes em sistemas orientados a eventos, análise de HTTP, alto desempenho e flexibilidade, além da capacidade de escrever seus próprios scripts Lua para gerar solicitações de teste.
Embora o wrk não tenha casos de teste e o autor apareça cerca de uma vez por ano para mesclar o código, isso não nos impede de usar o wrk como nossa ferramenta preferida para testes de desempenho e fuzz. Se você ainda está usando o ab multi-threaded, vale a pena experimentar o wrk.
A seguir está a parte estatística da distribuição de atraso dos resultados do wrk.
Latency Distribution
50% 1.20ms
75% 595.78ms
90% 899.11ms
99% 1.00s
Este exemplo significa que 50% das solicitações são concluídas em 1,2 ms, 90% das solicitações são concluídas em 899 ms e 99% das solicitações são concluídas em 1s.
Quando usamos o wrk para testar o estresse do nosso próprio produto, descobrimos que a maioria das solicitações nas estatísticas de latência do wrk eram concluídas em alguns milissegundos, mas uma pequena porcentagem das solicitações tinha uma latência superior a 100 milissegundos. Para um sistema construído com OpenResty, não é muito científico ter uma latência tão grande.
Embora a solução final para esse problema tenha sido muito simples, a análise e localização específicas foram um pouco complicadas e levaram vários dias. A solução final não é importante; o processo e a maneira de pensar sobre o problema é que são interessantes.
Quando encontramos problemas de latência, nossa primeira reação é que há algum bloqueio em algum lugar no código ou no sistema. Como o sistema é complexo, oferecemos gráficos de chamas.
Não há um script pronto do systemtap para analisar esse tipo de problema, então levou algum tempo para escrever um. No entanto, após ajustar o script do systemtap várias vezes, nenhum atraso significativo foi capturado, o que claramente não coincide com os resultados do wrk. Nós imaginamos que o script pode não ser perfeito e pode ter perdido algumas funções que não foram conectadas. Mas também temos dúvidas sobre a correção dos resultados do wrk.
Nós nos voltamos para tentar identificar se as estatísticas do wrk estão erradas ou se é realmente um problema do servidor. Despejamos todos os pacotes do teste de esmagamento no servidor onde o wrk está localizado, ordenamos pelo tempo gasto e ficamos surpresos ao descobrir que os resultados eram muito diferentes das estatísticas de latência do wrk, sem solicitações excedendo 100 milissegundos. Repeti o teste acima várias vezes e os resultados foram consistentes.
Agora o objetivo é claro, apenas suavizar o código do wrk sobre as estatísticas de atraso. A maior preocupação é que haja um bug nas estatísticas internas do wrk, o que não é fácil de corrigir, afinal, é um projeto sem nenhum caso de teste.
Nós revisamos a lógica de estatísticas do wrk e adicionamos logs no início e no final, e ficamos aliviados ao descobrir que as estatísticas sobre o atraso estavam corretas. Mas antes de imprimir os resultados finais, há um código de correção estatística.
if (complete / cfg.connections > 0) {
int64_t interval = runtime_us / (complete / cfg.connections);
stats_correct(statistics.latency, interval);
}
De acordo com este if, sempre que dados piezométricos são gerados, eles serão corrigidos. Se você estiver interessado, pode dar uma olhada no código da função stats_correct, são apenas 10 linhas, e eu não entendi mesmo depois de ler várias vezes.
Verifiquei novamente o registro de commit do código, pode haver algo, mas apenas a seguinte linha, e não entendi:
remove calibration & improve CO correction
Para reclamar, se o registro de submissão fosse um pouco mais detalhado, sem abreviação, ou adicionando um comentário no código, poderia economizar muitas coisas.
O problema foi verificado aqui, e pode ser confirmado que não é um problema do produto, e a solução já está lá, que é comentar o código de correção acima. Mas deve haver uma razão pela qual o autor do wrk deliberadamente o adicionou, e não entender a razão é sempre um problema oculto. Naturalmente, tive que abrir um issue para perguntar ao autor, e wg, que aparece uma vez por ano, deu uma resposta 15 dias depois, e acontece que a abreviação CO nas informações de commit acima se refere a Coordinated Omission, e dá um artigo dedicado a esse problema, estudantes interessados podem usar essa palavra-chave para pesquisar por si mesmos.
Resumindo, Coordinated Omission significa que ao fazer testes de estresse, não é suficiente contar apenas o tempo entre o envio e o recebimento de uma resposta, isso se refere ao tempo de serviço, o que perderá muitos problemas potenciais, e o tempo de espera da solicitação de teste também precisa ser contado, para ser considerado como tempo de resposta que os usuários se importam.
Gil Tene, que propôs o problema CO, também fez uma modificação no wrk para abordar especificamente o problema CO: https://github.com/giltene/wrk2, e o README deste projeto tem algumas explicações sobre isso, que você pode ler se estiver interessado, então não mencionarei aqui.
Para o nosso próprio produto, certamente não há bloqueio no código, e ao fazer testes de estresse, ele está executando a CPU ao máximo. Mesmo que haja bloqueio, há um gráfico de chamas para amostrar e analisar. Portanto, a correção simples e brutal que o wrk faz aqui para Coordinated Omission é bastante enganosa.